Time profiling - is using macros bad?

Question

I need to make a time profiling for several modules in Fortran, which means, that I'm supposed to write the same code in every beginning and every end of every function.

Really, it looks like this:

#ifdef TIME_PROFILING
            real :: t1, t2 !< Variables used for time storage
            call cpu_time(t1)
#endif

          *** FUNCTION CODE ***

#ifdef TIME_PROFILING
            call cpu_time(t2)
            write(*, "(A)") '+----------------+'
            write(*, "(A, E15.7, A)") '| TIME PROFILING | Function init_components() was running for ', t2-t1, 's.'
            write(*, "(A)") '+----------------+'
#endif

I was thinking about creating function, which would contain calling cpu_time() for the second time and the final message, but I don't think, it's enough. Still I'll be forced to write all the directives, to declare variables t1 and t2 and to call cpu_time() manually for the first time in every function.

Initially I wanted to make a separate module time_profiler_m for this function.

After thinking about disadvantages I came up with an idea of creating macros - that would allow me to write something like this:

#ifdef TIME_PROFILING
TIME_PROFILING_START
#endif

    *** FUNCTION CODE ***

#ifdef TIME_PROFILING
TIME_PROFILING_STOP
#endif

which is much shorter, but, on the other hand, I'm not sure about correctness of using macros like this and I'm pretty sure, that it is a pretty bad design to create a separate module for one macro.

So, what do you think is the correct design in this situation?

Answer 1

My thoughts are that timing function calls are a bit like logging. It's useful debugging information but maybe you don't want to always do it in your program. And what is standard practice for logging?

Generally you create module which deals with logging, and then you perform the appropriate call to log with a level (DEBUG, INFO, WARNING, ERROR). The module, based on its configuration, will then decide whether or not to log anything. It may be that the logging does nothing at all, but a call is still made.

You should probably consider doing something similar for timing. If timing is disabled, the call to mark the current time won't do anything. Similarly, the call to mark the difference won't do anything either.

It isn't the same as macros as macros are done pre-processor, so you are expending resources performing a call. However I would argue that it is worth it to do so. It means your program is capable of doing it should you deem it necessary, as opposed to compiling a version that does or doesn't do it.

It is somewhat subjective though, but I don't think that the performance loss is enough to merit turning it into a macro.