1
\$\begingroup\$

I'm getting back into C and I wrote this variadic logger as part of a chess application I'm writing. As such I'm looking for feedback about the general approach (I'm going to give it another pass to catch any possible errors, edge cases etc... later on). Mainly I'm concerned with side effects and trade-offs that I may not be aware of by using a solution like this.

The goal is to have a relatively portable, easy to use, and safe (as far as you can go without type checking) logger, that behaves like printf() but with some extra options.

So with all of that being said, please tell me why this is probably a bad idea in some shape or form.

Is variadic logging in C a sensible thing to do?

log.h

#ifndef CHX_LOG_H
#define CHX_LOG_H

typedef enum
{
    CHX_LOG_DEBUG,
    CHX_LOG_INFO,
    CHX_LOG_WARNING,
    CHX_LOG_ERROR,
    CHX_LOG_SILENT,
}chx_log_lvl;

typedef enum
{
    CHX_TAG_CLI,
    CHX_TAG_CORE,
    CHX_TAG_ERRORS,
}chx_tag;

#define CHX_LOG_ENABLED
#ifdef CHX_LOG_ENABLED

void chx_log(chx_log_lvl lvl, chx_tag tag, char* msg_tmpl, ...);

#define CHX_LOG(...) chx_log(__VA_ARGS__)
#define CHX_LOG_DEBUG(...) chx_log (CHX_LOG_DEBUG, __VA_ARGS__)
#define CHX_LOG_INFO(...) chx_log (CHX_LOG_INFO, __VA_ARGS__)
#define CHX_LOG_WARNING(...) chx_log (CHX_LOG_WARNING, __VA_ARGS__)
#define CHX_LOG_ERROR(...) chx_log (CHX_LOG_ERROR, __VA_ARGS__)

#else
#define CHX_LOG(...)
#define CHX_LOG_DEBUG(...)
#define CHX_LOG_INFO(...)
#define CHX_LOG_WARNING(...)
#define CHX_LOG_ERROR(...)
#endif

#endif

log.c

#include "log.h"
#include <stdarg.h>
#include <stdio.h>
#include <stdlib.h>
#include <unistd.h>

#ifdef CHX_LOG_ENABLED
void chx_log(chx_log_lvl lvl, chx_tag tag, char* msg_tmpl, ...)
{
    va_list msg_args;
    va_start(msg_args, msg_tmpl);
    char *chx_msg;
    if(vasprintf(&chx_msg, msg_tmpl, msg_args) == -1)
    {
            printf("Error formatting log... %s\n", msg_tmpl);
            exit(1);
    }
    va_end(msg_args);
    printf("%s", chx_msg);
    free(chx_msg);
}
#endif


Usage:

CHX_LOG_DEBUG(CHX_TAG_CLI, "cli_args:\n --player_side: %d\n --depth: %d\n --fen_path %s\n",
        cli_opts.player_side, cli_opts.depth, cli_opts.fen_path);
\$\endgroup\$
6
  • 1
    \$\begingroup\$ It's important that you add your compiler's attribute to mark this as accepting printf-like parameters \$\endgroup\$
    – Reinderien
    Jun 23, 2023 at 1:15
  • \$\begingroup\$ sorry I'm not sure if I understand why or how? \$\endgroup\$
    – blinken_lx
    Jun 23, 2023 at 1:18
  • \$\begingroup\$ What is your compiler? \$\endgroup\$
    – Reinderien
    Jun 23, 2023 at 1:36
  • \$\begingroup\$ from users.informatik.haw-hamburg.de/~krabat/FH-Labor/gnupro/… The format attribute specifies that a function takes printf or scanf style arguments which should be type-checked against a format string. For example, the following declaration causes the compiler to check the arguments in calls to my_ printf for consistency with the printf style format string argument, my_format. extern int my_printf (void *my_object, const char *my_format, ...) attribute ((format (printf, 2, 3))); \$\endgroup\$
    – blinken_lx
    Jun 23, 2023 at 21:19
  • \$\begingroup\$ @blinken_lx lvl and tag are not used in void chx_log(). Why are they in the parameter list? \$\endgroup\$ Jun 23, 2023 at 23:19

2 Answers 2

3
\$\begingroup\$

Reinventing the wheel

I have to do a big project. Let's start by rolling a logger. Bad idea, procrastination, there are plenty of loggers available. Also this is not so well suited for learning as having a look at other loggers will teach you more efficiently.

Non-standard concepts

Your "tag" is somewhat special. While the values "client" and "core" resemble what other loggers implement as "logger" or "logger_name", the value "error" on the other hand sounds much like log level. Currently the tag is ignored, indicating it is not required. Be careful not to add stuff which turns out to be useless or badly designed. I especially doubt the type. A generic string might be more useful (logger name, context, ...).

Log macros

Macros like LOG_DEBUG(...) are used by other loggers as well, but why? You use macros only for switching off logging completely during compile time. Something you usually do not want to do in a real project (maybe in a library). The real advantages of log macros are

  • you have access to predefined macros __FILE__, __LINE__
  • you may dynamically check the log level and avoid potentially costly parameter evaluations and the subsequent function call completely

Pass file name and line number to your logger and implement a level check within the macro.

Other stuff

  • The big #ifdef clause in the c-file is strange. Either do not include the file in your project or leave it to the linker to remove unreferenced code.
  • exit(1) - libraries exiting a program - usually a bad idea. Killing a mission critical program because of a null pointer passed. Print/log the problem, but do not exit.
\$\endgroup\$
3
  • \$\begingroup\$ thanks! Reinventing the wheel... - out of scope. Currently the tag is ignored, indicating it is not required... - tags will be used in future features You use macros only for switching off logging completely... - why compile unneeded code? macros FILE, LINE ... - excellent point, I should use these avoid ... parameter evaluations... - logging atm is used only during dev leave it to the linker to remove unreferenced code. - I see no reason to compile code that's not being used? exit(1) - libraries exiting a program... - In my case I do want it to die. \$\endgroup\$
    – blinken_lx
    Jun 23, 2023 at 18:20
  • \$\begingroup\$ surely there must be a better way to address feedback. comment character length is way too small. Thanks for the review! \$\endgroup\$
    – blinken_lx
    Jun 23, 2023 at 18:22
  • 2
    \$\begingroup\$ A review is not imperative, pick what fits. you are welcome :-) \$\endgroup\$
    – stefan
    Jun 23, 2023 at 22:27
0
\$\begingroup\$

Is variadic logging in C a sensible thing to do?

Yes.

IMO, the logging length should have a length limit, say 256?
A log is not a place to dump a tome. Since sample code uses "%s", long dumps are possible and of questionable value. We do not want logging to get in the way of normal program flow.


... goal is to have a relatively portable

vasprintf() is not part of the standard C library

I reviewed vasprintf() and find it troubling with its "If memory allocation wasn't possible, or some other error occurs, these functions will return -1, and the contents of strp is undefined." This allows for memory leaks as it is unclear if free(*strp) should happened.

Instead, consider alternatives.

  • One issue I have with ... logging is the potential for a long entry. The whole nature of logging is close to error handling and I prefer to avoid allocating during errors.
  • Impose a sane limit of log length - perhaps system 256 or BUFSIZ?
  • Use a const format.
  • Add sentinel characters to strings for clarity.
  • Be sure to flush if logging relates to an error. We definitely want to see this one.
  • System errors deserve to go out on stderr.

To that end, perhaps:

void chx_log_alt(chx_log_lvl lvl, chx_tag tag, const char* msg_tmpl, ...) {
  va_list msg_args;
  va_start(msg_args, msg_tmpl);
  char chx_msg[BUFSIZ];
  if (vsnprintf(chx_msg, BUFSIZ, msg_tmpl, msg_args) < 0) {
    fprintf(stderr, "Error formatting log... \"%s\"\n", msg_tmpl);
    exit(EXIT_FAILURE);
  }
  va_end(msg_args);
  printf("%s", chx_msg);
  if (lvl == CHX_LOG_ERROR) {
    fflush(stdout);
  }
}

vsnprintf() is part of the standard library.

Source

Consider adding into the CHX_LOG_... macros the caller's function name and maybe line number via __func__, __LINE__.

\$\endgroup\$
1
  • \$\begingroup\$ Thanks this is awesome feedback! \$\endgroup\$
    – blinken_lx
    Jun 23, 2023 at 23:15

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.