2014 Winter Project Week:Logging

• 

  Projects List

Key Investigators

• BWH: Nicole Aucoin
• Isomics: Steve Pieper
• Kitware: Jean-Cristophe Fillion-Robin
• Queen's: Csaba Pinter, Andras Lasso

Project Description

Objective

• Standardize logging in Slicer (correspondence)
• Explore logging to file

Approach, Plan

• Discuss unifying debug, warning and error logging over Qt and VTK based files
• Discuss back porting the message logger class to CTK
• Discuss UI features from a developer and user point of view
• Implement agreed upon changes

Progress

• See https://github.com/jcfr/CTK/tree/error-log-model-to-file
• Add file logging support to CTK
  • Added ctkFileLogger
  • Extended ctkErrorLogModel:
    • Specify in which file to log
    • Enable / Disable file logging
    • Set a file logging pattern (i.e. [%{level}][%{origin}] %{timestamp} [%{category}] (%{file}:%{line}) - %{msg})
  • Added tests (ctkFileLoggerTest, ctkErrorLogModelFileLoggingTest1, ctkVTKErrorLogModelFileLoggingTest1)

[DEBUG][Qt] 10.01.2014 11:23:22 [] (unknown:0) - This is a qDebug message
[WARNING][Qt] 10.01.2014 11:23:22 [] (unknown:0) - This is a qWarning message
[CRITICAL][Qt] 10.01.2014 11:23:22 [] (unknown:0) - This is a qCritical message
[INFO][Stream] 10.01.2014 11:23:22 [] (unknown:0) - This is a Cout message
[CRITICAL][Stream] 10.01.2014 11:23:22 [] (unknown:0) - This is a Cerr message
[INFO][FD] 10.01.2014 11:23:22 [] (unknown:0) - This is a stdout message
[CRITICAL][FD] 10.01.2014 11:23:22 [] (unknown:0) - This is a stderr message
[INFO][FD] 10.01.2014 11:23:22 [] (unknown:0) - This is a 2nd stdout message
[CRITICAL][FD] 10.01.2014 11:23:22 [] (unknown:0) - This is a 2nd stderr message
[WARNING][VTK] 10.01.2014 11:23:15 [vtkObject (0x8b9800)] (/home/jchris/Projects/Slicer-SuperBuild-Debug-Qt485/CTK/Libs/Visualization/VTK/Core/Testing/Cpp/ctkVTKErrorLogModelFileLoggingTest1.cpp:66) - This is a VTK warning message
[ERROR][VTK] 10.01.2014 11:23:15 [vtkObject (0x8b9800)] (/home/jchris/Projects/Slicer-SuperBuild-Debug-Qt485/CTK/Libs/Visualization/VTK/Core/Testing/Cpp/ctkVTKErrorLogModelFileLoggingTest1.cpp:67) - This is a VTK error message

Future

• Add file log rotation to ctkFileLogger
• Add missing VTK generic logging macros
• Add GUI in Slicer to configure logging to file (set logging level, number of log files to keep, etc.)

Discussion

• Logging macros:
  • Levels: error, warning, debug
  • Collect at each line: message + get the filename and line number automatically
  • Log to file: timestamp, level, file, line number, message
  • Macro names:
    • QT: use standard qDebug, qWarning, etc. macros - in QT5 they will provide everything that we need => Jc will check if these QT features can be backported
    • VTK: use standard vtkDebugMacro, vtkWarningMacro, etc. in VTK classes; outside VTK classes use generic VTK logging macros. Not all required macros exist => check how they could be added
• Logging to file:
  • All errors end up at CTK error model, so logging to file should be added there
  • Log rotation is needed (keep last N log files)
  • Write to file after each logged message
  • Make logging level configurable (by default error&warning only)

Reference

• Slicer developers mailings list correspondence
• Github topic branch removing asserts and using qCritical and vtkErrorMacros