[Serdev] logging framework changes

Maxim Sobolev sobomax at sippysoft.com
Mon Oct 13 23:53:51 CEST 2008


Good stuff, Ondrej. What we have found very useful over the years is 
adding some reference to the SIP messages in question (such as Call-Id) 
to the log output. Then you can easily correlate particular call flow 
with the errors/warnings that it has caused. Perhaps it's something you 
should consider adding at least as an opt-in:

That's the code we use in our private version to do it:

--- parser/msg_parser.c.orig
+++ parser/msg_parser.c
@@ -43,6 +43,8 @@
  #include <string.h>
  #include <stdlib.h>

+#include <siplog.h>
+
  #include "../comp_defs.h"
  #include "msg_parser.h"
  #include "parser_f.h"
@@ -626,6 +628,16 @@
         DBG("exiting parse_msg\n");
  #endif

+       parse_headers(msg, HDR_CALLID_F, 0);
+       if (msg->callid != NULL && msg->callid->body.len > 0) {
+               tmp = alloca(msg->callid->body.len + 1);
+               memcpy(tmp, msg->callid->body.s, msg->callid->body.len);
+               tmp[msg->callid->body.len] = '\0';
+               msg->log = siplog_open("ser", tmp, 0);
+       } else {
+               msg->log = NULL;
+       }
+
         return 0;

  error:
@@ -652,6 +664,7 @@
  /*only the content*/
  void free_sip_msg(struct sip_msg* msg)
  {
+       if (msg->log) siplog_close(msg->log);
         if (msg->new_uri.s) { pkg_free(msg->new_uri.s); 
msg->new_uri.len=0; }
         if (msg->dst_uri.s) { pkg_free(msg->dst_uri.s); 
msg->dst_uri.len=0; }
         if (msg->headers)     free_hdr_field_lst(msg->headers);


Ondrej Martinek wrote:
> Hi guys,
> 
> I've prepared a patch to SER logging framework that _automatically_ 
> prefix log messages with the log level and module name strings.  In 
> short, you no longer need to explicitly include the log level or module 
> name string in the message.
> 
> Eg.:
>    Instead of:
>       LOG(L_ERR, "tm: ERROR: something failed\n");
>    you will write:
>       ERR("something failed\n");
> 
> The new stderr/syslog format is:
> 
>    LEVEL: MODULE [FILE:LINE]: MESSAGE
>    LEVEL: MODULE: MESSAGE  ... if NO_DEBUG macro is defined
> 
> MODULE is "<core>" for the core and "<script>" for the ser.cfg generated 
> log messages.
> 
> Another feature is that LOG(L_...) macro is superseded by the 
> corresponding ERR/DBG/...() shorter equivalents (of course, it's still 
> used when the first argument isn't constant).
> 
> The main reason was to unify the log messages and enable their further 
> processing by text tools (filtering, colorification, you-name-it,...).
> 
> Since many log messages need to be updated I created a perl script that 
> fixes most of them in one shot:
>   - any log level and module name prefix is removed
>   - LOG(L_ERR/DBG/etc., ...) is replaced by shorter ERR/DBG/etc.() macros
>   - fix the messages where the log level and the prefix mismatch:
> 
>   Eg.: ERR vs. BUG
>        LOG(L_ERR, "BUG: tm: foo\n")
>     becomes:
>        BUG("foo\n");
> 
> 
> Note that because of this script the patch will touch a lot of files in 
> many modules.  Please feel free to ask about details, suggest or object 
> to the changes.  I plan to commit it soon if there will be no serious 
> objections.



-- 
Maksym Sobolyev
Sippy Software, Inc.
Internet Telephony (VoIP) Experts
T/F: +1-646-651-1110
Web: http://www.sippysoft.com


More information about the Serdev mailing list