Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > comp.lang.c > #26322

Re: Problem with printf-like logging framework and inline hexdumps.

Show all headers | View raw

On 13-09-12 20:26, Barry Schwarz wrote:
> On Thu, 13 Sep 2012 18:11:55 +0200, Jef Driesen
> <jefdriesen@hotmail.com.invalid> wrote:
>
>> Hi,
>>
>> For one of my projects, I created a simple logging framework. I have an
>> (opaque) context object which contains a buffer:
>>
>> typedef struct dc_context_t {
>>       char msg[4096];
>>       /* More stuff here. */
>> } dc_context_t;
>>
>> and a printf-like function to log a message. The logging function uses
>> the vsnprintf() function to write a string representation of the
>> arguments to the context buffer. The resulting string is then passed to
>> a user-defined callback function.
>>
>> int
>> dc_context_log (dc_context_t *context, const char *format, ...)
>> {
>>       va_list ap;
>>
>>       va_start (ap, format);
>>       vsnprintf (context->msg, sizeof (context->msg), format, ap);
>>       va_end (ap);
>>
>>       callback (context->msg);
>> }
>>
>> This works perfect for all printf-style logging. For example:
>>
>>      dc_context_log (context, "%s (%d)", "An error message", 3);
>>
>> However, I would like to log some binary data too. Let's say I want to
>> log a message with an inline hexdump, something like this:
>>
>>       "DEBUG: data=<DATA>, size=<SIZE>"
>>
>> Since there is no printf format string available for hexdumps, I could
>> write a little dc_context_hexdump() helper function to convert the
>> binary data into a hex string, and then produce the log message in 3
>> steps:
>>
>>       dc_context_log (context, "%s: data=", "DEBUG");
>>       dc_context_hexdump (context, hexdata, size);
>>       dc_context_log (context, "", size);
>>
>> This would work fine, except that I need the output in only one piece.
>> There are several reasons for that. I simplified the code a bit for this
>> post, but in reality the dc_context_log() function also receives extra
>> info, like the __FILE__ and __LINE__ macros. When printing the output, I
>> only want to see the file and line info appear only once, and not three
>> times. Also in a multithreaded environment, another thread may call the
>> logging function between each of the three calls, and thus interleaving
>> the output.
>>
>> How would you workaround this?
>>
>> A possible approach might be to convert the binary data to string
>> first, and then pass that to the dc_context_log call. Something like
>> this:
>>
>> void
>> somefunction (dc_context_t *context, unsigned char *data, unsigned int
>> size)
>> {
>>       /* Do something useful here. */
>>
>>       /* Log the binary data. */
>>       hexstr = hexdump (data, size);
>>       dc_context_log (context, "%s: data=%s, size=%u",
>>           "DEBUG", hexstr, size);
>> }
>>
>> But this hexdump function isn't thread-safe (because it would have to
>> return a pointer to a static buffer). And even if I would make a
>> re-entrant hexdump_r() version, it's not ideal because then I would have
>> to allocate a buffer inside the somefunction(). I don't want to do that
>> because the dc_context_log is actually called through a macro, which can
>> be configured at compile time to omit the actual call (e.g. in
>> production builds). But then the memory allocation would still be there,
>> and I don't want to pollute application code with #ifdef's. An temporary
>> buffer on the stack won't work either, because the size isn't fixed.
>
> You need a buffer that will survive after hexdump returns.  I can
> think of only three ways to achieve this: static, dynamic, and
> provided by somefunction.
>
> If you need hexdump to be thread safe, then static is probably not the
> answer.
>
> If you choose to allocate the buffer dynamically, it need not be done
> in somefunction.  It could be done in hexdump.  Either way though, it
> would need to be freed in somefunction after dc_context_log returns.
> You could insure that hexdump is called only when dc_context_log is
> about to be called by moving the assignment of hexstr into the
> argument list of the call to dc_context_log.  That is, replace
>        hexstr = hexdump (data, size);
>        dc_context_log (context, "%s: data=%s, size=%u",
>            "DEBUG", hexstr, size);
> with
>        dc_context_log (context, "%s: data=%s, size=%u",
>            "DEBUG", hexstr = hexdump (data, size), size);
> In this way, when your macro suppresses the call to dc_context_log it
> also suppresses the call to hexdump and no allocation is performed. If
> you initialize hexstr to NULL, then you can call free() regardless of
> whether an allocation has been performed or not and your code is not
> polluted.

One of the reasons to have the msg array embedded into the context structure is 
to avoid any memory allocations in the logging functions. The necessary memory 
is already pre-allocated with the context structure. With this approach the 
memory allocation would be re-introduced. But it's still an interesting idea of 
course.

> If you choose to define the buffer as an automatic array in
> somefunction, it need not be any bigger than the array msg in your
> structure.  You may not know how much of it you will use but you do
> know it cannot be any bigger or your call to vsnprintf will overrun
> members in the structure.

True, but the size of the msg array in the context structure isn't public. It's 
an opaque data structure and thus the size can be changed at will. And then the 
code would be out of sync again.

Jef

Back to comp.lang.c | Previous | Next — Previous in thread | Next in thread | Find similar | Unroll thread

Thread

Problem with printf-like logging framework and inline hexdumps. Jef Driesen <jefdriesen@hotmail.com.invalid> - 2012-09-13 18:11 +0200
  Re: Problem with printf-like logging framework and inline hexdumps. "Heinrich Wolf" <invalid@invalid.invalid> - 2012-09-13 18:55 +0200
    Re: Problem with printf-like logging framework and inline hexdumps. Jorgen Grahn <grahn+nntp@snipabacken.se> - 2012-09-20 17:19 +0000
  Re: Problem with printf-like logging framework and inline hexdumps. Barry Schwarz <schwarzb@dqel.com> - 2012-09-13 11:26 -0700
    Re: Problem with printf-like logging framework and inline hexdumps. Jef Driesen <jefdriesen@hotmail.com.invalid> - 2012-09-14 00:06 +0200
  Re: Problem with printf-like logging framework and inline hexdumps. Ben Bacarisse <ben.usenet@bsb.me.uk> - 2012-09-13 21:24 +0100
    Re: Problem with printf-like logging framework and inline hexdumps. Jef Driesen <jefdriesen@hotmail.com.invalid> - 2012-09-13 23:47 +0200
      Re: Problem with printf-like logging framework and inline hexdumps. Ben Bacarisse <ben.usenet@bsb.me.uk> - 2012-09-13 23:54 +0100
        Re: Problem with printf-like logging framework and inline hexdumps. Jef Driesen <jefdriesen@hotmail.com.invalid> - 2012-09-14 18:31 +0200
          Re: Problem with printf-like logging framework and inline hexdumps. Ben Bacarisse <ben.usenet@bsb.me.uk> - 2012-09-14 22:02 +0100
            Re: Problem with printf-like logging framework and inline hexdumps. Ben Bacarisse <ben.usenet@bsb.me.uk> - 2012-09-14 22:49 +0100
              Re: Problem with printf-like logging framework and inline hexdumps. Jef Driesen <jefdriesen@hotmail.com.invalid> - 2012-09-17 07:09 +0200
              Re: Problem with printf-like logging framework and inline hexdumps. Kaz Kylheku <kaz@kylheku.com> - 2012-09-17 06:39 +0000
                Re: Problem with printf-like logging framework and inline hexdumps. Ben Bacarisse <ben.usenet@bsb.me.uk> - 2012-09-17 13:30 +0100
      Re: Problem with printf-like logging framework and inline hexdumps. Nick Keighley <nick_keighley_nospam@hotmail.com> - 2012-09-14 03:29 -0700
        Re: Problem with printf-like logging framework and inline hexdumps. Ben Bacarisse <ben.usenet@bsb.me.uk> - 2012-09-14 12:01 +0100
  Re: Problem with printf-like logging framework and inline hexdumps. Jef Driesen <jefdriesen@hotmail.com.invalid> - 2012-09-14 22:50 +0200

csiph-web