Login / Register  0 items | $0.00 New#KVRDeals

Logging strategies

joshb
KVRist
 
60 posts since 13 Apr, 2016

Postby joshb; Sat Mar 18, 2017 5:00 pm Logging strategies

Hey guys,

As I'm in the middle of beta testing my first plugin instrument, the bigger bugs have been weeded out and now I'm getting into the weeds...the weird, unpredictable, wtf bugs that only users in the real world can dig up.

I realized that I've never used logs in a meaningful way. Sure, I've always output some bits to the console as I've developed, but I've never thought to generate a log file that a user could send me to help debug some esoteric issue. I'm starting to realize that logging should be added to my tool belt, but I don't know where to start or have a useful strategy.

So...how do you use logs? It seems that there's some sweet spot between logging everything and logging next to nothing, but what's been the most useful to you? Especially as it concerns debugging audio plugins.

Thank you for your wisdom.
stratum
KVRian
 
1303 posts since 29 May, 2012

Postby stratum; Sun Mar 19, 2017 2:05 am Re: Logging strategies

Probably not applicable to plugins, but for a library with a very large code base within which one cannot remember everything, logging is a nice way to create bugs. A function calls the logger and the logger calls some common utility function which in turn happens to be calling the logger! :oops:
~stratum~
PurpleSunray
KVRian
 
684 posts since 13 Mar, 2012

Postby PurpleSunray; Sun Mar 19, 2017 3:56 am Re: Logging strategies

I use logging a lot. Have never introduced a bug with it, but found many :D

Basically, I log everything that could be interesting.
Starts from "trace" level for low-level libs, to "debug" for level-low for app-code. "info" for stuff you also want to see on non-debug builds and "error" for important stuff.

But don't use any "logging-framework" just a couple of macros:

Code: Select all
/*****************************************************************************
   function name logging for GCC
*****************************************************************************/

#if defined(__GNUC__)
#define _LOGFUNCTION_ (strrchr(__FILE__, '/') ? strrchr(__FILE__, '/') + 1 : __FILE__)
#else
#define _LOGFUNCTION_ __FUNCTION__
#endif

/*****************************************************************************
   log macros
*****************************************************************************/

#define LOG_ERROR(fmt, ...) log_error(_LOGFUNCTION_, __LINE__, fmt, ##__VA_ARGS__)
#define LOG_INFO(fmt, ...) log_info(_LOGFUNCTION_, __LINE__, fmt, ##__VA_ARGS__)

#if defined(_DEBUG)
   // apps shall use this:
   #define LOG_DEBUG(fmt, ...) log_debug(_LOGFUNCTION_, __LINE__, fmt, ##__VA_ARGS__)
   // libs shall use this:
   #define LOG_TRACE(fmt, ...) log_trace(_LOGFUNCTION_, __LINE__, fmt, ##__VA_ARGS__)
#else
   // apps shall use this:
   #define LOG_DEBUG(...)
   // libs shall use this:
   #define LOG_TRACE(...)
#endif   


Code: Select all

/*****************************************************************************
   writelog
   Write to stdout (+ VS debug out on windows)
*****************************************************************************/

static void writelog(
   const char* prefix,
   const char* func,
   int line,
   const char * szformat,
   va_list args)
{
   int thread_id = 0;

#ifdef WIN32
   thread_id = (int) GetCurrentThreadId();
#else
   thread_id = (int) pthread_self();
#endif

   timespec time;
   clock_gettime(CLOCK_REALTIME, &time);

   String logbuff;
   logbuff.formatv(szformat, args);
   
   String outbuf;
   outbuff.format("%s %02d:%02d:%02d.%06d T%04u %s line %d: %s\n",
         prefix,
         (int)(time.tv_sec / 3600) % 24,
         (int)(time.tv_sec / 60) % 60,
         (int)(time.tv_sec % 60),
         (int)(time.tv_nsec / 1000),
         thread_id,
         func,
         line,
         logbuff.ptr());
   
#ifdef WIN32
   OutputDebugStringA(outbuf.ptr());
#endif

   puts(outbuf.ptr());
}

/*****************************************************************************
   log level functions
*****************************************************************************/

void log_error(const char* file, int line, const char * szformat, ...)
{
   if (g_log_level <= LogLevel_Error)
   {
      va_list args;
      va_start(args, szformat);
      {
         writelog("ERROR", file, line, szformat, args);
      }
      va_end(args);
   }
}

void log_info(const char* file, int line, const char * szformat, ...)
{
   if (g_log_level <= LogLevel_Info)
   {
      va_list args;
      va_start(args, szformat);
      {
         writelog("INFO", file, line, szformat, args);
      }
      va_end(args);
   }
}
..


writelog function is adapted to other/new log targets (file, other logging framework, ..) as I need it.
Last edited by PurpleSunray on Sun Mar 19, 2017 4:03 am, edited 1 time in total.
stratum
KVRian
 
1303 posts since 29 May, 2012

Postby stratum; Sun Mar 19, 2017 4:02 am Re: Logging strategies

When the complexity of the logger increases it can easily become a source of additional bugs. Perhaps using a logging framework would be a good idea.
~stratum~
joshb
KVRist
 
60 posts since 13 Apr, 2016

Postby joshb; Sun Mar 19, 2017 11:02 pm Re: Logging strategies

I use JUCE so I was already thinking of using it's logging system.

But I talking about about what and when you log something...especially as it applies to a plugin. What information have you found useful and what's been a waste?

Moderator: Moderators (Main)

Return to DSP and Plug-in Development