"SQL worked" messages on the console

[lassoan]

Lots of "SQL worked" messages are logged in the console when the application is built in debug mode.

I don't think that successful operations need to be logged, especially with this frequency. Setting to TRACE level might be considered, but the performance hit may be significant. So, the best would be to remove these logs or be able to optionally include it with #ifdef/#endif.

[Punzo]

for the moment I have set those logging (i.e. ctkDICOMDatabase) at trace level in https://github.com/commontk/CTK/pull/1184. NOTE ctk levels: 1) debug mode: debug 2) release mode: warn

setting those logging to trace, clean 90% of the logging in debug mode. Note that if the level is debug and a static logger calls logger.trace, the additional computations are only an if condition if (d->LogLevel <= ctkErrorLogLevel::LogLevel::Trace) https://github.com/commontk/CTK/blob/master/Libs/Core/ctkLogger.cpp#L72-L80

[lassoan]

the additional computations are only an if condition if (d->LogLevel <= ctkErrorLogLevel::LogLevel::Trace)

The significant extra computation cost comes from fully preparing the input log message, regardless of log level.

For example, "SQL worked!\n SQL: " + query.lastQuery() and similar string operations can be expensive. Since database operations are expensive as well, the overhead is probably acceptable.

[Punzo]

or example, "SQL worked!\n SQL: " + query.lastQuery() and similar string operations can be expensive. Since database operations are expensive as well, the overhead is probably acceptable.

uhm that's true, you are right. I will add #ifdef/#endif.

[jcfr]

I will add #ifdef/#endif.

I think having the ability to toggle the level at runtime makes sense.

Unless you were talking about excluding some code based on the debug/release, I am not sure we will want to add #ifdef/#endif associated a "trace" CMake option

[Punzo]

hey guys,

in https://github.com/commontk/CTK/pull/1184 I did the following: 1) Changed the majority of the logging of the ctkDICOMDatabase from logger.debug to logger.trace 2) I have set the default ctk logging level as debug in debug modeand warn in release mode 3) I have added a cmake option CTK_ENABLE_TRACE with relative #ifdef/#endif (https://github.com/commontk/CTK/pull/1184/commits/ac5febb16b513e714c39710181fa0e877d44c1f5)

I can revert (3) if you think it is not necessary/not the best.

Finally yes be able to change the ctk log level at run time (as we can do for DCMTK) would also be desiderable (however not necesary for https://github.com/commontk/CTK/pull/1184). We would need to change the logging infrastructure to a proper logging design (i.e. using "getLoggerInstance" etc...) (probably better to do in a different PR respect to https://github.com/commontk/CTK/pull/1184).

[Punzo]

@lassoan regarding (3), we could use #ifndef QT_NO_DEBUG instead of the CTK_ENABLE_TRACE CMake option as suggested by @jcfr. See https://github.com/commontk/CTK/pull/1184/commits/3687e3f2ae575802a1d0e0402df6633d7e4a38cd

Like this in release mode, the trace logging is completely excluded. In debug mode the logger.trace calls are enabled, but they will not print to terminal unless you change the logging level to trace.

[lassoan]

I agree that log level should be adjustable at runtime. But trace level logs are a special case. Many times you see trace level logging code commented out. This is the case in CTK, too: in the single class where trace-level log is used (in ctkVTKAbstractView.cpp), the lines are commented out. This is because usually you need these very low level logs extremely rarely (probably only once, when you debugged some complex issues) and then you don't want to slow down the application with them. Traces can be inexpensive if they are implemented with a macro, but by using logger.trace() the log message is always created, regardless of the current log level.

we could use #ifndef QT_NO_DEBUG as suggested by @jcfr.

Behavior changes depending on debug/non-debug mode should be avoided. Any extra calls or missed calls in devbug mode can change the application behavior so that a bug in release mode cannot be reproduced in debug mode. So, unless there is no other way of solving some issue, I would not add QT_NO_DEBUG-dependent behavior.

I would prefer a simple solution, such as:

• A. deleting the trace level log code
• B. adding a local #define (and #ifdef/#endif around trace level log code) in the .cpp file that developers can enable when troubleshooting some tough issues
• C. add a macro for trace level logging (that would avoid putting constructing the log message if there is no trace level log)
• D. comment out the trace level log code

My order of preference is A = most preferred, D = least preferred, but all acceptable.

It would be better to do this in a separate PR from #1184 because that PR is too big and contains another mostly unrelated feature.

[Punzo]

@lassoan ok I opened a PR for (A) https://github.com/commontk/CTK/pull/1187. Please have a look if you want to "save" some of the logging that I have removed (I removed all the ones that makes the terminal very dirty).