Xen devel - Mar 2011 - [PATCH] tools: ocaml: fix the logging in the ocaml libxl bindings

# HG changeset patch
# User David Scott <dave.scott@eu.citrix.com>
# Date 1300913511 0
# Node ID 67525892e2c6ee27c25438d43699397c5a3e0272
# Parent  3831bd253e02aa0536ed32e936777d026abb955e
tools: ocaml: fix the logging in the ocaml libxl bindings.

We now:
1. ensure the caml_logger fields have sensible initial values
2. adopt the policy that, if the messages won''t fit into the buffer
then
   they are dropped and clipped is set to 1. The default buffer size is 2KiB
   which ought to be large enough unless the logging is very spammy (which
   is arguably a problem in itself)

Signed-off-by: David Scott <dave.scott@eu.citrix.com>

diff -r 3831bd253e02 -r 67525892e2c6 tools/ocaml/libs/xl/xl_stubs.c
--- a/tools/ocaml/libs/xl/xl_stubs.c	Mon Mar 21 18:07:06 2011 +0000
+++ b/tools/ocaml/libs/xl/xl_stubs.c	Wed Mar 23 20:51:51 2011 +0000
@@ -28,12 +28,21 @@
 
 #include "libxl.h"
 
+#define MAX_LOG_LEN 2048
+
 struct caml_logger {
 	struct xentoollog_logger logger;
 	int log_offset;
-	char log_buf[2048];
+	char log_buf[MAX_LOG_LEN];
+	int clipped; /* Set to 1 if some log messages won''t fit in the buffer
*/
 };
 
+void log_create(struct caml_logger *logger)
+{
+	logger->log_offset = 0;
+	logger->clipped = 0;
+}	
+
 typedef struct caml_gc {
 	int offset;
 	void *ptrs[64];
@@ -43,16 +52,32 @@
                   int errnoval, const char *context, const char *format,
va_list al)
 {
 	struct caml_logger *ologger = (struct caml_logger *) logger;
+	int remaining, written;
 
-	ologger->log_offset += vsnprintf(ologger->log_buf +
ologger->log_offset,
-	                                 2048 - ologger->log_offset, format, al);
+	if (ologger->clipped)
+		return; /* if we''ve already started clipping, drop everything */
+
+	/* If the message doesn''t fit in the buffer, we drop it and set
clipped to 1.
+	   This shouldn''t happen unless the logging is very spammy. */
+
+	remaining = sizeof(ologger->log_buf) - ologger->log_offset;
+	written = vsnprintf(ologger->log_buf + ologger->log_offset, remaining,
format, al);
+	if (written < 0)
+		return; /* nothing really we can do */
+	if (written < remaining){
+		ologger->log_offset += written;
+		return;
+	}
+	/* buffer isn''t big enough */
+	ologger->clipped = 1;
 }
 
 void log_destroy(struct xentoollog_logger *logger)
 {
 }
 
-#define INIT_STRUCT() libxl_ctx ctx; struct caml_logger lg; struct caml_gc gc;
gc.offset = 0;
+
+#define INIT_STRUCT() libxl_ctx ctx; struct caml_logger lg; struct caml_gc gc;
gc.offset = 0; log_create(&lg);
 
 #define INIT_CTX()  \
 	lg.logger.vmessage = log_vmessage; \

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xensource.com
http://lists.xensource.com/xen-devel

David Scott writes ("[Xen-devel] [PATCH] tools: ocaml: fix the logging in
the ocaml libxl bindings"):
> tools: ocaml: fix the logging in the ocaml libxl bindings.
> 
> We now:
> 1. ensure the caml_logger fields have sensible initial values
> 2. adopt the policy that, if the messages won''t fit into the
buffer then
>    they are dropped and clipped is set to 1. The default buffer size is
2KiB
>    which ought to be large enough unless the logging is very spammy (which
>    is arguably a problem in itself)
Thanks, but:

 * Can you make a version where the line lengths do not exceed 75 ?
   That allows for a patch +/- column, plus a couple of levels of
   quoting, to fit in an 80-column window.

 * Now that I read this code I''m very confused.  Why does log_vmessage
   not actually output the message anywhere ?  Looking at the code,
   the buffer is printed out only if the call fails (I assume that''s
   what failwith_xl is).  That''s not right.  What about debugging
   output ?

   There is no guarantee that the logger will be called to report any
   particular number of messages if a libxl call fails.  Specifically,
   it may output zero error messages, or several one, before returning
   a failure code.  And it will frequently output a number of
   informational messages.

Ian.

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xensource.com
http://lists.xensource.com/xen-devel

Hi,
> David Scott writes ("[Xen-devel] [PATCH] tools: ocaml: fix the logging
> in the ocaml libxl bindings"):
> > tools: ocaml: fix the logging in the ocaml libxl bindings.
[ snip ]

Ian Jackson replied:
> Thanks, but:
> 
>  * Can you make a version where the line lengths do not exceed 75 ?
>    That allows for a patch +/- column, plus a couple of levels of
>    quoting, to fit in an 80-column window.
Will do. I think I''ve got into a habit of writing very long lines.
I blame my poor choice in editors and email clients :-)
>  * Now that I read this code I''m very confused.  Why does
log_vmessage
>    not actually output the message anywhere ?  Looking at the code,
>    the buffer is printed out only if the call fails (I assume
that''s
>    what failwith_xl is).  That''s not right.  What about debugging
>    output ?
> 
>    There is no guarantee that the logger will be called to report any
>    particular number of messages if a libxl call fails.  Specifically,
>    it may output zero error messages, or several one, before returning
>    a failure code.  And it will frequently output a number of
>    informational messages.
That is indeed the current behaviour -- most log messages end up dropped,
only those which are in the buffer when the libxl call fails get bubbled
up to the user in an exception. The main difference after my patch is
that the code nolonger segfaults after calling (IIRC) gettopologyinfo 
and hopefully won''t blow its buffer if the logging ever gets spammy :-)

If you recommend changing the policy to always record/handle all log 
messages then that sounds fine to me. From the point of view of the 
ocaml code I can think of the following options (Vincent: do you have any
advice?):

1. add the notion of a per-call context to the ocaml and associate 
   logging callbacks with this. The ocaml code can then do whatever it 
   likes on a per-call basis.

2. allow the ocaml to set a global logging callback which would handle
   logging from all ocaml xl calls in the same process

3. allow the ocaml to set some syslog logging parameters so all ocaml xl
   calls would just log via syslog

I don''t think any of these are particularly complicated. Anyone have
any
thoughts / recommendations / preferences / suggestions?

Cheers,
Dave


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xensource.com
http://lists.xensource.com/xen-devel

On Thu, 2011-03-31 at 23:57 +0100, Dave Scott wrote:
> Hi,
> 
> > David Scott writes ("[Xen-devel] [PATCH] tools: ocaml: fix the
logging
> > in the ocaml libxl bindings"):
> > > tools: ocaml: fix the logging in the ocaml libxl bindings.
> [ snip ]
> 
> Ian Jackson replied:
> > Thanks, but:
> > 
> >  * Can you make a version where the line lengths do not exceed 75 ?
> >    That allows for a patch +/- column, plus a couple of levels of
> >    quoting, to fit in an 80-column window.
> 
> Will do. I think I''ve got into a habit of writing very long lines.
> I blame my poor choice in editors and email clients :-)
I blame your massive widescreen monitor ;-)
> 
> >  * Now that I read this code I''m very confused.  Why does
log_vmessage
> >    not actually output the message anywhere ?  Looking at the code,
> >    the buffer is printed out only if the call fails (I assume
that''s
> >    what failwith_xl is).  That''s not right.  What about
debugging
> >    output ?
> > 
> >    There is no guarantee that the logger will be called to report any
> >    particular number of messages if a libxl call fails.  Specifically,
> >    it may output zero error messages, or several one, before returning
> >    a failure code.  And it will frequently output a number of
> >    informational messages.
> 
> That is indeed the current behaviour -- most log messages end up dropped,
> only those which are in the buffer when the libxl call fails get bubbled
> up to the user in an exception. The main difference after my patch is
> that the code nolonger segfaults after calling (IIRC) gettopologyinfo 
> and hopefully won''t blow its buffer if the logging ever gets
spammy :-)
> 
> If you recommend changing the policy to always record/handle all log 
> messages then that sounds fine to me. From the point of view of the 
> ocaml code I can think of the following options (Vincent: do you have any
> advice?):
> 
> 1. add the notion of a per-call context to the ocaml and associate 
>    logging callbacks with this. The ocaml code can then do whatever it 
>    likes on a per-call basis.
> 
> 2. allow the ocaml to set a global logging callback which would handle
>    logging from all ocaml xl calls in the same process
> 
> 3. allow the ocaml to set some syslog logging parameters so all ocaml xl
>    calls would just log via syslog
> 
> I don''t think any of these are particularly complicated. Anyone
have any
> thoughts / recommendations / preferences / suggestions?
Somewhat of an aside but what do you think of having libxl contexts with
longer lifespans than the current one per libxl call model? e.g. you
would open a context in ocaml code, make a series of calls and then
close it? Or perhaps even keep it for the lifetime of a domain or a
thread of processing context etc?

Ian.
> 
> Cheers,
> Dave
> 
> 
> _______________________________________________
> Xen-devel mailing list
> Xen-devel@lists.xensource.com
> http://lists.xensource.com/xen-devel


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xensource.com
http://lists.xensource.com/xen-devel

Dave Scott writes ("RE: [Xen-devel] [PATCH] tools: ocaml: fix the logging
in the ocaml libxl bindings"):
> That is indeed the current behaviour -- most log messages end up dropped,
> only those which are in the buffer when the libxl call fails get bubbled
> up to the user in an exception. The main difference after my patch is
> that the code nolonger segfaults after calling (IIRC) gettopologyinfo 
> and hopefully won''t blow its buffer if the logging ever gets
spammy :-)
Right :-).  Fair enough.
> If you recommend changing the policy to always record/handle all log 
> messages then that sounds fine to me. From the point of view of the 
> ocaml code I can think of the following options (Vincent: do you have any
> advice?):
I think the ocaml bindings to libxl should expose the actual interface
of libxl, without messing with the semantics of errors in this way.

I don''t know which of these:
> 1. add the notion of a per-call context to the ocaml and associate 
>    logging callbacks with this. The ocaml code can then do whatever it 
>    likes on a per-call basis.
> 
> 2. allow the ocaml to set a global logging callback which would handle
>    logging from all ocaml xl calls in the same process
> 
> 3. allow the ocaml to set some syslog logging parameters so all ocaml xl
>    calls would just log via syslog
... would be more sensible from an ocaml point of view.

Ian.

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xensource.com
http://lists.xensource.com/xen-devel