Dirk Craeynest created PROTON-2245:
--------------------------------------

             Summary: Logging issues in messenger.c
                 Key: PROTON-2245
                 URL: https://issues.apache.org/jira/browse/PROTON-2245
             Project: Qpid Proton
          Issue Type: Bug
          Components: proton-c
    Affects Versions: proton-c-0.31.0
            Reporter: Dirk Craeynest


With the new QPID Proton library 0.31 to which we upgraded, the application can 
control the logging via the subsystem and severity masks of the loggers 
(typically by modifying the setup of the pn_default_logger at startup).

So, for example, we find in file memory.c:
  if (PN_SHOULD_LOG(logger, PN_SUBSYSTEM_MEMORY, PN_LEVEL_DEBUG)) {
    pn_logger_logf(logger, PN_SUBSYSTEM_MEMORY, PN_LEVEL_DEBUG, "Memory 
allocation stats:");
    ...
 and the macro PN_SHOULD_LOG will verify (fast) that the call to pn_logger_logf 
is to be done, when trace is really desired.

But we have calls that do not have this 'if', e.g. in messenger.c, we have:
  case PN_CONNECTION_INIT:
    pn_logf("connection created: %p", (void *) pn_event_connection(event));
    break;

where pn_logf is a macro:
  #define pn_logf(...) \
    do { \
           if (pni_log_enabled()) \
               pni_logf_impl(__VA_ARGS__); \
    } while(0)

where pni_log_enabled will just return a boolean (true if logging was enabled).
 Then pni_logf_impl is called,
which then calls pni_vlogf_impl,
 which then calls
  pni_logger_vlogf(pn_default_logger(), PN_SUBSYSTEM_ALL, PN_LEVEL_TRACE, fmt, 
ap);
 which then formats the string and calls
  pni_logger_log(logger, subsystem, severity, pn_string_get(logger->scratch));
 which then unconditionally calls the logger->sink
 (and the default sink of the pn_default_logger unconditionally writes the msg.

It looks to us that the call to pni_log_enabled() in pn_logf should in fact be 
something like:
    if (PN_SHOULD_LOG(logger, PN_SUBSYSTEM_ALL, PN_LEVEL_TRACE)) { \
      pni_logf_impl(__VA_ARGS__); \

so as to have a consistent logging control.

Currently, it looks like the logging done via pn_logf is using an alternate 
mechanism than the central mechanism.
 As far as we can see, only messenger.c contains such pn_logf "unprotected" 
calls ...

So messenger.c should likely be converted to the new way to log things.

 

Extra logging issues, all in messenger.c:

Some calls to pn_logf are done when the level should be error, but as pn_logf 
is called, the severity is hardcoded to TRACE.  See pn_error_report in 
messenger.c

Most of the errors are *not* traced, they are just stored in the messenger.  
One could have expected that when logging of ERROR level is asked, that any 
error would be logged.

 



--
This message was sent by Atlassian Jira
(v8.3.4#803005)

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@qpid.apache.org
For additional commands, e-mail: dev-h...@qpid.apache.org

Reply via email to