Patchwork [PATCHv2,3/4] qxl: add debug_cs and cmdlog_cs

login
register
mail settings
Submitter Alon Levy
Date April 28, 2011, 8:29 a.m.
Message ID <1303979358-4421-4-git-send-email-alevy@redhat.com>
Download mbox | patch
Permalink /patch/93199/
State New
Headers show

Comments

Alon Levy - April 28, 2011, 8:29 a.m.
With this you can output the command log and/or the guest debug (driver)
output to a chardev instead of stderr:

-global qxl-vga.cmdlog_chardev=qxl_cmdlog_chardev
-global qxl-vga.debug_chardev=qxl_debug_chardev

useful for debugging. if no chardev is specified prints to stderr like the old
code.
---
 hw/qxl-logger.c |   62 ++++++++++++++++++++++++++++++++++--------------------
 hw/qxl.c        |   14 +++++++++++-
 hw/qxl.h        |    2 +
 3 files changed, 54 insertions(+), 24 deletions(-)
Gerd Hoffmann - April 29, 2011, 12:09 p.m.
On 04/28/11 10:29, Alon Levy wrote:
> With this you can output the command log and/or the guest debug (driver)
> output to a chardev instead of stderr:
>
> -global qxl-vga.cmdlog_chardev=qxl_cmdlog_chardev
> -global qxl-vga.debug_chardev=qxl_debug_chardev
>
> useful for debugging. if no chardev is specified prints to stderr like the old
> code.

Hmm.  That is a bit too much ad-hoc debug hacking IMHO.  Also I'm not 
sure I like the idea to send debug stuff through chardev instead of just 
writing them to stderr or some logfile.

I do see why you are doing that though.  Unfortunaly qemu has no sane 
debug logging infrastructure.  This is long overdue IMHO, so we don't 
need hacks like this one and also don't reinvent stuff over and over.

cheers,
   Gerd
Alon Levy - April 29, 2011, 10:19 p.m.
On Fri, Apr 29, 2011 at 02:09:54PM +0200, Gerd Hoffmann wrote:
> On 04/28/11 10:29, Alon Levy wrote:
> >With this you can output the command log and/or the guest debug (driver)
> >output to a chardev instead of stderr:
> >
> >-global qxl-vga.cmdlog_chardev=qxl_cmdlog_chardev
> >-global qxl-vga.debug_chardev=qxl_debug_chardev
> >
> >useful for debugging. if no chardev is specified prints to stderr like the old
> >code.
> 
> Hmm.  That is a bit too much ad-hoc debug hacking IMHO.  Also I'm
> not sure I like the idea to send debug stuff through chardev instead
> of just writing them to stderr or some logfile.
> 
> I do see why you are doing that though.  Unfortunaly qemu has no
> sane debug logging infrastructure.  This is long overdue IMHO, so we
> don't need hacks like this one and also don't reinvent stuff over
> and over.

The bigger hack called "qxl_terse" I didn't even send :) ok, so now I get
to either keep this in my closet or think of how to do a minimal acceptable
qemu logging infrastructure that would let me register a logging handle and
use that to redirect to a chardev (they would all default to being muxed over
stdio?)

QemuLogger *qemu_create_logger(const char *logger_id);
 - logger_id is used to match to the chardev given on the command line
 - need to prevent collision, so probably easier to have a logger_id be an int
 and have that looked up to a string in an automatically generated table?

struct QemuLogger {
  CharDriverState *chr;
};

And command line would be:
 -chardev bla,id=myid -debug qxl,myid

qxl->logger = qemu_create_logger("qxl");
qemu_chr_write(qxl->logger->chr, ..)

logger creation would have to happen before command line parsing, so in the device initialization.

Sounds right?

> 
> cheers,
>   Gerd
>
Gerd Hoffmann - May 2, 2011, 9:02 a.m.
Hi,

> The bigger hack called "qxl_terse" I didn't even send :) ok, so now I get
> to either keep this in my closet or think of how to do a minimal acceptable
> qemu logging infrastructure that would let me register a logging handle and
> use that to redirect to a chardev (they would all default to being muxed over
> stdio?)
>
> QemuLogger *qemu_create_logger(const char *logger_id);
>   - logger_id is used to match to the chardev given on the command line
>   - need to prevent collision, so probably easier to have a logger_id be an int
>   and have that looked up to a string in an automatically generated table?

What I have in mind is a simple dbg_print() function, integrated with 
qdev and simliar to what the linux kernel has, i.e. something like:

int dbg_print(DeviceState *qdev, int loglevel, const char *fmt, ...);

This can basically be used that as drop-in replacement for the 
fprintf(stderr, fmt, ...) style found in many drivers.

dbg_print would get the driver name via qdev->info->name, get the 
instance via qdev->parent_bus->info->get_dev_path(), get a timestamp, 
then create a standard prefix for all messages for easy grepping.  It 
would also check qdev->loglevel to figure whenever the message should be 
printed or not.  All devices get a property to set qdev->loglevel, so 
all logging can be configured at runtime per device.

Messages go to stderr by default.  A -debug switch could be added to 
route them another way.

Comments in the idea?

cheers,
   Gerd
Alon Levy - May 2, 2011, 10:12 a.m.
On Mon, May 02, 2011 at 11:02:22AM +0200, Gerd Hoffmann wrote:
>   Hi,
> 
> >The bigger hack called "qxl_terse" I didn't even send :) ok, so now I get
> >to either keep this in my closet or think of how to do a minimal acceptable
> >qemu logging infrastructure that would let me register a logging handle and
> >use that to redirect to a chardev (they would all default to being muxed over
> >stdio?)
> >
> >QemuLogger *qemu_create_logger(const char *logger_id);
> >  - logger_id is used to match to the chardev given on the command line
> >  - need to prevent collision, so probably easier to have a logger_id be an int
> >  and have that looked up to a string in an automatically generated table?
> 
> What I have in mind is a simple dbg_print() function, integrated
> with qdev and simliar to what the linux kernel has, i.e. something
> like:
> 
> int dbg_print(DeviceState *qdev, int loglevel, const char *fmt, ...);
> 
> This can basically be used that as drop-in replacement for the
> fprintf(stderr, fmt, ...) style found in many drivers.
> 
> dbg_print would get the driver name via qdev->info->name, get the
> instance via qdev->parent_bus->info->get_dev_path(), get a
> timestamp, then create a standard prefix for all messages for easy
> grepping.  It would also check qdev->loglevel to figure whenever the
> message should be printed or not.  All devices get a property to set
> qdev->loglevel, so all logging can be configured at runtime per
> device.
> 
> Messages go to stderr by default.  A -debug switch could be added to
> route them another way.
> 
> Comments in the idea?

The thing with grepping is that it conflicts with using the monitor on stdout,
which is why I wanted to use a chardev. And of course a chardev solves the
need for grep (at least to get a coarse level - of course you still need to
grep later).

dbg_print takes care of making it standard to have a loglevel and prefix, sounds
good, but I'd still like to know if it is acceptable to also redirect with -debug,
I guess reusing the DeviceState then, instead of my added struct, so just letting
DeviceState.debug_chardev == NULL by default, and settable with
-debug <devname>,id=<chardev_id>

> 
> cheers,
>   Gerd
> 
>
Gerd Hoffmann - May 2, 2011, 10:25 a.m.
Hi,

> dbg_print takes care of making it standard to have a loglevel and prefix, sounds
> good, but I'd still like to know if it is acceptable to also redirect with -debug,
> I guess reusing the DeviceState then, instead of my added struct, so just letting
> DeviceState.debug_chardev == NULL by default, and settable with
> -debug<devname>,id=<chardev_id>

Making dbg_print use DeviceState.debug_chardev (if present, stderr 
otherwise) looks sane to me.  Buf I'd use standard properties then to 
set it instead of a separate -debug switch, i.e.

   -chardev file,id=messages,path=... \
   -device foo,dbg=1,dbglog=messages

cheers,
   Gerd
Alon Levy - May 2, 2011, 10:33 a.m.
On Mon, May 02, 2011 at 12:25:30PM +0200, Gerd Hoffmann wrote:
>   Hi,
> 
> >dbg_print takes care of making it standard to have a loglevel and prefix, sounds
> >good, but I'd still like to know if it is acceptable to also redirect with -debug,
> >I guess reusing the DeviceState then, instead of my added struct, so just letting
> >DeviceState.debug_chardev == NULL by default, and settable with
> >-debug<devname>,id=<chardev_id>
> 
> Making dbg_print use DeviceState.debug_chardev (if present, stderr
> otherwise) looks sane to me.  Buf I'd use standard properties then
> to set it instead of a separate -debug switch, i.e.
> 
>   -chardev file,id=messages,path=... \
>   -device foo,dbg=1,dbglog=messages
> 

Sounds good. I'll try to make it so.

> cheers,
>   Gerd
>
Jan Kiszka - May 2, 2011, 10:37 a.m.
On 2011-05-02 12:33, Alon Levy wrote:
> On Mon, May 02, 2011 at 12:25:30PM +0200, Gerd Hoffmann wrote:
>>   Hi,
>>
>>> dbg_print takes care of making it standard to have a loglevel and prefix, sounds
>>> good, but I'd still like to know if it is acceptable to also redirect with -debug,
>>> I guess reusing the DeviceState then, instead of my added struct, so just letting
>>> DeviceState.debug_chardev == NULL by default, and settable with
>>> -debug<devname>,id=<chardev_id>
>>
>> Making dbg_print use DeviceState.debug_chardev (if present, stderr
>> otherwise) looks sane to me.  Buf I'd use standard properties then
>> to set it instead of a separate -debug switch, i.e.
>>
>>   -chardev file,id=messages,path=... \
>>   -device foo,dbg=1,dbglog=messages
>>
> 
> Sounds good. I'll try to make it so.

We have a tracing infrastructure for such use cases today. Better invest
in adding missing features there.

Jan
Markus Armbruster - May 2, 2011, 11 a.m.
Jan Kiszka <jan.kiszka@siemens.com> writes:

> On 2011-05-02 12:33, Alon Levy wrote:
>> On Mon, May 02, 2011 at 12:25:30PM +0200, Gerd Hoffmann wrote:
>>>   Hi,
>>>
>>>> dbg_print takes care of making it standard to have a loglevel and prefix, sounds
>>>> good, but I'd still like to know if it is acceptable to also redirect with -debug,
>>>> I guess reusing the DeviceState then, instead of my added struct, so just letting
>>>> DeviceState.debug_chardev == NULL by default, and settable with
>>>> -debug<devname>,id=<chardev_id>
>>>
>>> Making dbg_print use DeviceState.debug_chardev (if present, stderr
>>> otherwise) looks sane to me.  Buf I'd use standard properties then
>>> to set it instead of a separate -debug switch, i.e.
>>>
>>>   -chardev file,id=messages,path=... \
>>>   -device foo,dbg=1,dbglog=messages
>>>
>> 
>> Sounds good. I'll try to make it so.
>
> We have a tracing infrastructure for such use cases today. Better invest
> in adding missing features there.

Start with docs/tracing.txt
Alon Levy - May 2, 2011, 11:50 a.m.
On Mon, May 02, 2011 at 01:00:01PM +0200, Markus Armbruster wrote:
> Jan Kiszka <jan.kiszka@siemens.com> writes:
> 
> > On 2011-05-02 12:33, Alon Levy wrote:
> >> On Mon, May 02, 2011 at 12:25:30PM +0200, Gerd Hoffmann wrote:
> >>>   Hi,
> >>>
> >>>> dbg_print takes care of making it standard to have a loglevel and prefix, sounds
> >>>> good, but I'd still like to know if it is acceptable to also redirect with -debug,
> >>>> I guess reusing the DeviceState then, instead of my added struct, so just letting
> >>>> DeviceState.debug_chardev == NULL by default, and settable with
> >>>> -debug<devname>,id=<chardev_id>
> >>>
> >>> Making dbg_print use DeviceState.debug_chardev (if present, stderr
> >>> otherwise) looks sane to me.  Buf I'd use standard properties then
> >>> to set it instead of a separate -debug switch, i.e.
> >>>
> >>>   -chardev file,id=messages,path=... \
> >>>   -device foo,dbg=1,dbglog=messages
> >>>
> >> 
> >> Sounds good. I'll try to make it so.
> >
> > We have a tracing infrastructure for such use cases today. Better invest
> > in adding missing features there.
> 
> Start with docs/tracing.txt

ok, I see that the file starts by saying it is meant to be used for debugging as
well. Am I correct in the following?
1. to change tracing backends requires a recompile
2. can't have two tracing backends at the same time (i.e. either everything goes
to stdout or everything is visible via systemtap etc.)
3. quoting:
         Do not pass in string arguments.
   how does that help debugging then?
4. the equivalent of setting a loglevel is?

If I want to achieve my original intend, namely easily changing the target of specific
qxl debug statements from stderr to a separate file, to view at runtime, I will need to:
1. turn all of them to trace calls
2. do one of:
 2.a turn the stderr backend into a debug_chardev backend, defaulting to stderr
 (this sounds simplest to me) and add this option
 2.b augment the simpletrace backend in the same way.

Any comments?

Alon
Jan Kiszka - May 2, 2011, 12:43 p.m.
On 2011-05-02 13:50, Alon Levy wrote:
> On Mon, May 02, 2011 at 01:00:01PM +0200, Markus Armbruster wrote:
>> Jan Kiszka <jan.kiszka@siemens.com> writes:
>>
>>> On 2011-05-02 12:33, Alon Levy wrote:
>>>> On Mon, May 02, 2011 at 12:25:30PM +0200, Gerd Hoffmann wrote:
>>>>>   Hi,
>>>>>
>>>>>> dbg_print takes care of making it standard to have a loglevel and prefix, sounds
>>>>>> good, but I'd still like to know if it is acceptable to also redirect with -debug,
>>>>>> I guess reusing the DeviceState then, instead of my added struct, so just letting
>>>>>> DeviceState.debug_chardev == NULL by default, and settable with
>>>>>> -debug<devname>,id=<chardev_id>
>>>>>
>>>>> Making dbg_print use DeviceState.debug_chardev (if present, stderr
>>>>> otherwise) looks sane to me.  Buf I'd use standard properties then
>>>>> to set it instead of a separate -debug switch, i.e.
>>>>>
>>>>>   -chardev file,id=messages,path=... \
>>>>>   -device foo,dbg=1,dbglog=messages
>>>>>
>>>>
>>>> Sounds good. I'll try to make it so.
>>>
>>> We have a tracing infrastructure for such use cases today. Better invest
>>> in adding missing features there.
>>
>> Start with docs/tracing.txt
> 
> ok, I see that the file starts by saying it is meant to be used for debugging as
> well. Am I correct in the following?
> 1. to change tracing backends requires a recompile

Right. I mostly work with stderr backend as it can be redirected
wherever you want it (console, file, ftrace trace_marker).

> 2. can't have two tracing backends at the same time (i.e. either everything goes
> to stdout or everything is visible via systemtap etc.)
> 3. quoting:
>          Do not pass in string arguments.
>    how does that help debugging then?

This needs to be fixed, the infrastructure should be able to record
fixed sized strings (not kilobytes, but 32 bytes or so).

> 4. the equivalent of setting a loglevel is?

Right now either the use of systemtap or ust which allow per-tracepoint
enabling/disabling or enable simpletrace and use the trace-event monitor
command. On top you need local grouping of the tracepoints.

At least the latter needs fixing so that the developer of some module
can tag tracepoints in-tree. But I also think we should be tracepoint
control a generic feature, independent of the tracer backend as far as
possible (ust and systemtap likely provide interfaces to forward control
commands).

> 
> If I want to achieve my original intend, namely easily changing the target of specific
> qxl debug statements from stderr to a separate file, to view at runtime, I will need to:
> 1. turn all of them to trace calls
> 2. do one of:
>  2.a turn the stderr backend into a debug_chardev backend, defaulting to stderr
>  (this sounds simplest to me) and add this option

You should avoid using too much of qemu's infrastructure in the tracer,
specifically if holds some state. Or am I misunderstanding your plans?

>  2.b augment the simpletrace backend in the same way.
> 
> Any comments?
> 
> Alon

Jan
Alon Levy - May 2, 2011, 1:04 p.m.
On Mon, May 02, 2011 at 02:43:34PM +0200, Jan Kiszka wrote:
> On 2011-05-02 13:50, Alon Levy wrote:
> > On Mon, May 02, 2011 at 01:00:01PM +0200, Markus Armbruster wrote:
> >> Jan Kiszka <jan.kiszka@siemens.com> writes:
> >>
> >>> On 2011-05-02 12:33, Alon Levy wrote:
> >>>> On Mon, May 02, 2011 at 12:25:30PM +0200, Gerd Hoffmann wrote:
> >>>>>   Hi,
> >>>>>
> >>>>>> dbg_print takes care of making it standard to have a loglevel and prefix, sounds
> >>>>>> good, but I'd still like to know if it is acceptable to also redirect with -debug,
> >>>>>> I guess reusing the DeviceState then, instead of my added struct, so just letting
> >>>>>> DeviceState.debug_chardev == NULL by default, and settable with
> >>>>>> -debug<devname>,id=<chardev_id>
> >>>>>
> >>>>> Making dbg_print use DeviceState.debug_chardev (if present, stderr
> >>>>> otherwise) looks sane to me.  Buf I'd use standard properties then
> >>>>> to set it instead of a separate -debug switch, i.e.
> >>>>>
> >>>>>   -chardev file,id=messages,path=... \
> >>>>>   -device foo,dbg=1,dbglog=messages
> >>>>>
> >>>>
> >>>> Sounds good. I'll try to make it so.
> >>>
> >>> We have a tracing infrastructure for such use cases today. Better invest
> >>> in adding missing features there.
> >>
> >> Start with docs/tracing.txt
> > 
> > ok, I see that the file starts by saying it is meant to be used for debugging as
> > well. Am I correct in the following?
> > 1. to change tracing backends requires a recompile
> 
> Right. I mostly work with stderr backend as it can be redirected
> wherever you want it (console, file, ftrace trace_marker).
> 
> > 2. can't have two tracing backends at the same time (i.e. either everything goes
> > to stdout or everything is visible via systemtap etc.)
> > 3. quoting:
> >          Do not pass in string arguments.
> >    how does that help debugging then?
> 
> This needs to be fixed, the infrastructure should be able to record
> fixed sized strings (not kilobytes, but 32 bytes or so).
> 
> > 4. the equivalent of setting a loglevel is?
> 
> Right now either the use of systemtap or ust which allow per-tracepoint
> enabling/disabling or enable simpletrace and use the trace-event monitor
> command. On top you need local grouping of the tracepoints.
> 
> At least the latter needs fixing so that the developer of some module
> can tag tracepoints in-tree. But I also think we should be tracepoint
> control a generic feature, independent of the tracer backend as far as
> possible (ust and systemtap likely provide interfaces to forward control
> commands).
> 
> > 
> > If I want to achieve my original intend, namely easily changing the target of specific
> > qxl debug statements from stderr to a separate file, to view at runtime, I will need to:
> > 1. turn all of them to trace calls
> > 2. do one of:
> >  2.a turn the stderr backend into a debug_chardev backend, defaulting to stderr
> >  (this sounds simplest to me) and add this option
> 
> You should avoid using too much of qemu's infrastructure in the tracer,
> specifically if holds some state. Or am I misunderstanding your plans?
> 

My original patch allowed logging of qxl debug output to a chardev of my choice. I'm
trying to achieve the same thing using the tracing framework. The way is I think to
add a DeviceState.debug_chardev that is settable when the device is created (no state
in the tracing framework) and use that from the stderr framework.

This seems to be a little bit difficult with the current stderr backend implementation
which never has any handle to a DeviceState. I'll have to fix that, and then it can
be something like:

static inline void trace_$name(DeviceState *dev, $args)
{
    if (!dev || !dev->debug_chardev) {
        fprintf(stderr, "$name $fmt\n" $argnames);
    else {
        qemu_chr_print("$name $fmt\n" $argnames);
    }
}



> >  2.b augment the simpletrace backend in the same way.
> > 
> > Any comments?
> > 
> > Alon
> 
> Jan
> 
> -- 
> Siemens AG, Corporate Technology, CT T DE IT 1
> Corporate Competence Center Embedded Linux
Paolo Bonzini - May 2, 2011, 2:09 p.m.
On 05/02/2011 02:43 PM, Jan Kiszka wrote:
>> >  4. the equivalent of setting a loglevel is?
> Right now either the use of systemtap or ust which allow per-tracepoint
> enabling/disabling or enable simpletrace and use the trace-event monitor
> command. On top you need local grouping of the tracepoints.

There is a pending patch series for -trace events, which will do 99% of 
what you need and in some cases is even better than loglevels.

Paolo

Patch

diff --git a/hw/qxl-logger.c b/hw/qxl-logger.c
index 76f43e6..df6e78b 100644
--- a/hw/qxl-logger.c
+++ b/hw/qxl-logger.c
@@ -99,6 +99,22 @@  static const char *qxl_v2n(const char *n[], size_t l, int v)
 }
 #define qxl_name(_list, _value) qxl_v2n(_list, ARRAY_SIZE(_list), _value)
 
+static void qxl_log_printf(PCIQXLDevice *qxl, const char *format, ...)
+{
+    va_list ap;
+    uint8_t buf[4096];
+
+    va_start(ap, format);
+    if (qxl->cmdlog_cs) {
+        vsnprintf((char *)buf, sizeof(buf), format, ap);
+        buf[sizeof(buf) - 1] = '\0';
+        qemu_chr_write(qxl->cmdlog_cs, buf, strlen((char*)buf));
+    } else {
+        vfprintf(stderr, format, ap);
+    }
+    va_end(ap);
+}
+
 static void qxl_log_image(PCIQXLDevice *qxl, QXLPHYSICAL addr, int group_id)
 {
     QXLImage *image;
@@ -106,11 +122,11 @@  static void qxl_log_image(PCIQXLDevice *qxl, QXLPHYSICAL addr, int group_id)
 
     image = qxl_phys2virt(qxl, addr, group_id);
     desc = &image->descriptor;
-    fprintf(stderr, " (id %" PRIx64 " type %d flags %d width %d height %d",
+    qxl_log_printf(qxl, " (id %" PRIx64 " type %d flags %d width %d height %d",
             desc->id, desc->type, desc->flags, desc->width, desc->height);
     switch (desc->type) {
     case SPICE_IMAGE_TYPE_BITMAP:
-        fprintf(stderr, ", fmt %d flags %d x %d y %d stride %d"
+        qxl_log_printf(qxl, ", fmt %d flags %d x %d y %d stride %d"
                 " palette %" PRIx64 " data %" PRIx64,
                 image->bitmap.format, image->bitmap.flags,
                 image->bitmap.x, image->bitmap.y,
@@ -118,12 +134,12 @@  static void qxl_log_image(PCIQXLDevice *qxl, QXLPHYSICAL addr, int group_id)
                 image->bitmap.palette, image->bitmap.data);
         break;
     }
-    fprintf(stderr, ")");
+    qxl_log_printf(qxl, ")");
 }
 
-static void qxl_log_rect(QXLRect *rect)
+static void qxl_log_rect(PCIQXLDevice *qxl, QXLRect *rect)
 {
-    fprintf(stderr, " %dx%d+%d+%d",
+    qxl_log_printf(qxl, " %dx%d+%d+%d",
             rect->right - rect->left,
             rect->bottom - rect->top,
             rect->left, rect->top);
@@ -131,17 +147,17 @@  static void qxl_log_rect(QXLRect *rect)
 
 static void qxl_log_cmd_draw_copy(PCIQXLDevice *qxl, QXLCopy *copy, int group_id)
 {
-    fprintf(stderr, " src %" PRIx64,
+    qxl_log_printf(qxl, " src %" PRIx64,
             copy->src_bitmap);
     qxl_log_image(qxl, copy->src_bitmap, group_id);
-    fprintf(stderr, " area");
-    qxl_log_rect(&copy->src_area);
-    fprintf(stderr, " rop %d", copy->rop_descriptor);
+    qxl_log_printf(qxl, " area");
+    qxl_log_rect(qxl, &copy->src_area);
+    qxl_log_printf(qxl, " rop %d", copy->rop_descriptor);
 }
 
 static void qxl_log_cmd_draw(PCIQXLDevice *qxl, QXLDrawable *draw, int group_id)
 {
-    fprintf(stderr, ": surface_id %d type %s effect %s",
+    qxl_log_printf(qxl, ": surface_id %d type %s effect %s",
             draw->surface_id,
             qxl_name(qxl_draw_type, draw->type),
             qxl_name(qxl_draw_effect, draw->effect));
@@ -155,13 +171,13 @@  static void qxl_log_cmd_draw(PCIQXLDevice *qxl, QXLDrawable *draw, int group_id)
 static void qxl_log_cmd_draw_compat(PCIQXLDevice *qxl, QXLCompatDrawable *draw,
                                     int group_id)
 {
-    fprintf(stderr, ": type %s effect %s",
+    qxl_log_printf(qxl, ": type %s effect %s",
             qxl_name(qxl_draw_type, draw->type),
             qxl_name(qxl_draw_effect, draw->effect));
     if (draw->bitmap_offset) {
-        fprintf(stderr, ": bitmap %d",
+        qxl_log_printf(qxl, ": bitmap %d",
                 draw->bitmap_offset);
-        qxl_log_rect(&draw->bitmap_area);
+        qxl_log_rect(qxl, &draw->bitmap_area);
     }
     switch (draw->type) {
     case QXL_DRAW_COPY:
@@ -172,11 +188,11 @@  static void qxl_log_cmd_draw_compat(PCIQXLDevice *qxl, QXLCompatDrawable *draw,
 
 static void qxl_log_cmd_surface(PCIQXLDevice *qxl, QXLSurfaceCmd *cmd)
 {
-    fprintf(stderr, ": %s id %d",
+    qxl_log_printf(qxl, ": %s id %d",
             qxl_name(qxl_surface_cmd, cmd->type),
             cmd->surface_id);
     if (cmd->type == QXL_SURFACE_CMD_CREATE) {
-        fprintf(stderr, " size %dx%d stride %d format %s (count %d, max %d)",
+        qxl_log_printf(qxl, " size %dx%d stride %d format %s (count %d, max %d)",
                 cmd->u.surface_create.width,
                 cmd->u.surface_create.height,
                 cmd->u.surface_create.stride,
@@ -184,7 +200,7 @@  static void qxl_log_cmd_surface(PCIQXLDevice *qxl, QXLSurfaceCmd *cmd)
                 qxl->guest_surfaces.count, qxl->guest_surfaces.max);
     }
     if (cmd->type == QXL_SURFACE_CMD_DESTROY) {
-        fprintf(stderr, " (count %d)", qxl->guest_surfaces.count);
+        qxl_log_printf(qxl, " (count %d)", qxl->guest_surfaces.count);
     }
 }
 
@@ -192,17 +208,17 @@  void qxl_log_cmd_cursor(PCIQXLDevice *qxl, QXLCursorCmd *cmd, int group_id)
 {
     QXLCursor *cursor;
 
-    fprintf(stderr, ": %s",
+    qxl_log_printf(qxl, ": %s",
             qxl_name(qxl_cursor_cmd, cmd->type));
     switch (cmd->type) {
     case QXL_CURSOR_SET:
-        fprintf(stderr, " +%d+%d visible %s, shape @ 0x%" PRIx64,
+        qxl_log_printf(qxl, " +%d+%d visible %s, shape @ 0x%" PRIx64,
                 cmd->u.set.position.x,
                 cmd->u.set.position.y,
                 cmd->u.set.visible ? "yes" : "no",
                 cmd->u.set.shape);
         cursor = qxl_phys2virt(qxl, cmd->u.set.shape, group_id);
-        fprintf(stderr, " type %s size %dx%d hot-spot +%d+%d"
+        qxl_log_printf(qxl, " type %s size %dx%d hot-spot +%d+%d"
                 " unique 0x%" PRIx64 " data-size %d",
                 qxl_name(spice_cursor_type, cursor->header.type),
                 cursor->header.width, cursor->header.height,
@@ -210,7 +226,7 @@  void qxl_log_cmd_cursor(PCIQXLDevice *qxl, QXLCursorCmd *cmd, int group_id)
                 cursor->header.unique, cursor->data_size);
         break;
     case QXL_CURSOR_MOVE:
-        fprintf(stderr, " +%d+%d", cmd->u.position.x, cmd->u.position.y);
+        qxl_log_printf(qxl, " +%d+%d", cmd->u.position.x, cmd->u.position.y);
         break;
     }
 }
@@ -223,8 +239,8 @@  void qxl_log_command(PCIQXLDevice *qxl, const char *ring, QXLCommandExt *ext)
     if (!qxl->cmdlog) {
         return;
     }
-    fprintf(stderr, "qxl-%d/%s:", qxl->id, ring);
-    fprintf(stderr, " cmd @ 0x%" PRIx64 " %s%s", ext->cmd.data,
+    qxl_log_printf(qxl, "qxl-%d/%s:", qxl->id, ring);
+    qxl_log_printf(qxl, " cmd @ 0x%" PRIx64 " %s%s", ext->cmd.data,
             qxl_name(qxl_type, ext->cmd.type),
             compat ? "(compat)" : "");
 
@@ -244,5 +260,5 @@  void qxl_log_command(PCIQXLDevice *qxl, const char *ring, QXLCommandExt *ext)
         qxl_log_cmd_cursor(qxl, data, ext->group_id);
         break;
     }
-    fprintf(stderr, "\n");
+    qxl_log_printf(qxl, "\n");
 }
diff --git a/hw/qxl.c b/hw/qxl.c
index ccd820c..ecab001 100644
--- a/hw/qxl.c
+++ b/hw/qxl.c
@@ -933,6 +933,7 @@  static void ioport_write(void *opaque, uint32_t addr, uint32_t val)
 {
     PCIQXLDevice *d = opaque;
     uint32_t io_port = addr - d->io_base;
+    uint8_t guest_debug_cs_buf[QXL_LOG_BUF_SIZE];
 
     switch (io_port) {
     case QXL_IO_RESET:
@@ -984,8 +985,15 @@  static void ioport_write(void *opaque, uint32_t addr, uint32_t val)
         qxl_set_mode(d, val, 0);
         break;
     case QXL_IO_LOG:
+        d->ram->log_buf[QXL_LOG_BUF_SIZE - 1] = '\0';
         if (d->guestdebug) {
-            fprintf(stderr, "qxl/guest: %s", d->ram->log_buf);
+            if (d->debug_cs) {
+                snprintf((char*)guest_debug_cs_buf, QXL_LOG_BUF_SIZE, "%ld %s",
+                         qemu_get_clock_ns(vm_clock), d->ram->log_buf);
+                qemu_chr_write(d->debug_cs, guest_debug_cs_buf, strlen((char*)guest_debug_cs_buf));
+            } else {
+                fprintf(stderr, "qxl/guest: %s", d->ram->log_buf);
+            }
         }
         break;
     case QXL_IO_RESET:
@@ -1514,6 +1522,8 @@  static PCIDeviceInfo qxl_info_primary = {
         DEFINE_PROP_UINT32("debug", PCIQXLDevice, debug, 0),
         DEFINE_PROP_UINT32("guestdebug", PCIQXLDevice, guestdebug, 0),
         DEFINE_PROP_UINT32("cmdlog", PCIQXLDevice, cmdlog, 0),
+        DEFINE_PROP_CHR("debug_chardev", PCIQXLDevice, debug_cs),
+        DEFINE_PROP_CHR("cmdlog_chardev", PCIQXLDevice, cmdlog_cs),
         DEFINE_PROP_END_OF_LIST(),
     }
 };
@@ -1532,6 +1542,8 @@  static PCIDeviceInfo qxl_info_secondary = {
         DEFINE_PROP_UINT32("debug", PCIQXLDevice, debug, 0),
         DEFINE_PROP_UINT32("guestdebug", PCIQXLDevice, guestdebug, 0),
         DEFINE_PROP_UINT32("cmdlog", PCIQXLDevice, cmdlog, 0),
+        DEFINE_PROP_CHR("debug_chardev", PCIQXLDevice, debug_cs),
+        DEFINE_PROP_CHR("cmdlog_chardev", PCIQXLDevice, cmdlog_cs),
         DEFINE_PROP_END_OF_LIST(),
     }
 };
diff --git a/hw/qxl.h b/hw/qxl.h
index f6c450d..2384c4e 100644
--- a/hw/qxl.h
+++ b/hw/qxl.h
@@ -22,6 +22,8 @@  typedef struct PCIQXLDevice {
     uint32_t           debug;
     uint32_t           guestdebug;
     uint32_t           cmdlog;
+    CharDriverState   *debug_cs;
+    CharDriverState   *cmdlog_cs;
     enum qxl_mode      mode;
     uint32_t           cmdflags;
     int                generation;