Tagged processor logs

[damb]

Features and changes:

• Tag processor log messages, hierarchically. I.e.

  12:29:16 [debug] [560a7b3d-ba2c-4758-b36a-639b13152395::e1959691-08e7-410d-b5a1-97be7608392d] [2020-12-24T12:19:07.208393Z - 2020-12-24T12:19:15.668393Z]: fit=0.295794, lag=3.330000
  12:29:16 [debug] [560a7b3d-ba2c-4758-b36a-639b13152395] Detector result: [2020-12-24T12:19:07.208393Z - 2020-12-24T12:19:15.668393Z] fit=0.295794, trigger_on=0.300000, trigger_off=0.250000, trigger_duration=60.000000
  12:29:20 [debug] [560a7b3d-ba2c-4758-b36a-639b13152395::e1959691-08e7-410d-b5a1-97be7608392d] [2020-12-24T12:19:11.448393Z - 2020-12-24T12:19:19.828393Z]: fit=0.201437, lag=4.290000
  12:29:20 [debug] [560a7b3d-ba2c-4758-b36a-639b13152395] Detector result: [2020-12-24T12:19:11.668393Z - 2020-12-24T12:19:19.828393Z] fit=0.201437, trigger_on=0.300000, trigger_off=0.250000, trigger_duration=60.000000

In this example 560a7b3d-ba2c-4758-b36a-639b13152395 is the Detector identifier, while e1959691-08e7-410d-b5a1-97be7608392d is the Template processor identifier.

Closes: #1

[damb]

Since the SeisComP logging API makes extensively use of preprocessor macros, I went also for an macro based implementation. However, a warning is issued when compiling:

/home/damb/work/projects/seiscomp/src/extras/scdetect/src/apps/scdetect/app.cpp:495:67: warning: ISO C++11 requires at least one argument for the "..." in a variadic macro
  495 |   SCDETECT_LOG_DEBUG_TAGGED(processor->id(), "Creating origin ...");
      |                                                                   ^
/home/damb/work/projects/seiscomp/src/extras/scdetect/src/apps/scdetect/app.cpp:597:78: warning: ISO C++11 requires at least one argument for the "..." in a variadic macro
  597 |     SCDETECT_LOG_DEBUG_TAGGED(processor->id(), "Sending event parameters ...");
      |                                                                              ^
/home/damb/work/projects/seiscomp/src/extras/scdetect/src/apps/scdetect/app.cpp:635:70: warning: ISO C++11 requires at least one argument for the "..." in a variadic macro
  635 |                                 "Sending of event parameters failed.");

As the warning states, this is due to not passing an argument to a variadic macro.

I've had a look at https://gcc.gnu.org/onlinedocs/gcc/Variadic-Macros.html and as far as I understand I'm using the ## operator where required. Though, still the warning. Hmm.

@luca-s, could you have a look at it, please? That would be great. Thanks.

[luca-s]

@damb the issue is that you are using a GNU extension of the pre-processor and the code is probably compiled with -Wpedantic, which warns against any non-standard features

[damb]

@damb the issue is that you are using a GNU extension of the pre-processor and the code is probably compiled with -Wpedantic, which warns against any non-standard features

Thanks. There is still this ugly work-around:

SCDETECT_LOG_DEBUG_TAGGED(processor->id(), "%s", "Log me tagged");

Things will change with C++2a, see: https://gcc.gnu.org/onlinedocs/cpp/Variadic-Macros.html

[luca-s]

Thanks. There is still this ugly work-around:

I agree, but if you want to go ugly (which sometimes is necessary), then do it in the definition of the macro instead of going ugly each time the macro is used. The definition is easier to change later.

#define SCDETECT_LOG_DEBUG_TAGGED(tag_str, ...)                        \
  SCDETECT_LOG_DEBUG( (stringify("[%s] ", tag_str) + stringify(__VA_ARGS__)).c_str() )

This is standard c++11 and stringify is a SeisComP function. The macro has not been tested, but that's just to give you an idea of a possible solution.

[damb]

I agree, but if you want to go ugly (which sometimes is necessary), then do it in the definition of the macro instead of going ugly each time the macro is used. The definition is easier to change later.

You're absolutely right, we should keep the code DRY.

[luca-s]

I have just realized there is a bug: the string result of stringify cannot be passed as first argument of SCDETECT_LOG_DEBUG, because that string will be interpreted (if there are % then the code would break). This is the fix:

#define SCDETECT_LOG_DEBUG_TAGGED(tag_str, ...)                                \
  SCDETECT_LOG_DEBUG("[%s] %s", tag_str.c_str(), Core::stringify(__VA_ARGS__).c_str())

[damb]

Thanks for the hint.