Difference between revisions of "2014 Winter Project Week:Logging"

From NAMIC Wiki
Jump to: navigation, search
(Page created)
 
 
(9 intermediate revisions by 4 users not shown)
Line 2: Line 2:
 
<gallery>
 
<gallery>
 
Image:PW-SLC2014.png|[[2014_Winter_Project_Week#Projects|Projects List]]
 
Image:PW-SLC2014.png|[[2014_Winter_Project_Week#Projects|Projects List]]
−
Image:SlicerRT_0.12_PatientHierarchy_ProstateEclipseLoaded.png|Screenshot from [http://www.slicer.org/slicerWiki/index.php/Documentation/Nightly/Modules/PatientHierarchy SlicerRT 0.12]
 
 
</gallery>
 
</gallery>
  
Line 23: Line 22:
 
<div style="width: 27%; float: left; padding-right: 3%;">
 
<div style="width: 27%; float: left; padding-right: 3%;">
 
<h3>Approach, Plan</h3>
 
<h3>Approach, Plan</h3>
−
*  
+
* 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
  
 
</div>
 
</div>
 
<div style="width: 27%; float: left; padding-right: 3%;">
 
<div style="width: 27%; float: left; padding-right: 3%;">
 
<h3>Progress</h3>
 
<h3>Progress</h3>
−
*
+
* 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. <code>[%{level}][%{origin}] %{timestamp} [%{category}] (%{file}:%{line}) - %{msg}</code>)
 +
** Added tests (ctkFileLoggerTest, ctkErrorLogModelFileLoggingTest1, ctkVTKErrorLogModelFileLoggingTest1)
 +
 
 +
<pre>
 +
[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
 +
</pre>
 +
 
 +
<h3>Future</h3>
 +
* Add file log rotation to ctkFileLogger
 +
<!-- * Ensure multiple process can log in the same file (Backport Qt5 [http://qt-project.org/doc/qt-5.1/qtcore/qlockfile.html QFileLock]?) -->
 +
* 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.)
 +
 
 
</div>
 
</div>
 +
 +
==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 ==
 
== Reference ==
 
* [http://slicer-devel.65872.n3.nabble.com/Use-proper-null-pointer-checking-instead-of-assert-tp4030168p4030569.html Slicer developers mailings list correspondence]
 
* [http://slicer-devel.65872.n3.nabble.com/Use-proper-null-pointer-checking-instead-of-assert-tp4030168p4030569.html Slicer developers mailings list correspondence]
 +
*[https://github.com/naucoin/Slicer/compare/3526-use-checking-instead-of-assert Github topic branch removing asserts and using qCritical and vtkErrorMacros]

Latest revision as of 17:16, 10 January 2014

Home < 2014 Winter Project Week:Logging

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

Retrieved from "https://www.na-mic.org/w/index.php?title=2014_Winter_Project_Week:Logging&oldid=85071"