doc: Add developer documentation for JUL logging
authorGeneviève Bastien <gbastien+lttng@versatic.net>
Wed, 13 Jul 2016 13:25:54 +0000 (09:25 -0400)
committerGenevieve Bastien <gbastien+lttng@versatic.net>
Tue, 6 Sep 2016 19:29:58 +0000 (15:29 -0400)
This explains the guidelines to add logging statements to Trace Compass

Change-Id: I2f2dd4a110150da9700049cf775bc4dbfcf90f75
Signed-off-by: Geneviève Bastien <gbastien+lttng@versatic.net>
Reviewed-on: https://git.eclipse.org/r/77247
Reviewed-by: Matthew Khouzam <matthew.khouzam@ericsson.com>
Reviewed-by: Hudson CI
doc/org.eclipse.tracecompass.doc.dev/doc/Developer-Guide.mediawiki

index df4597d7e63e30c5bdf79b297d6acff4348d9d90..4e1772f6b9265e643a8d1e1571720f9f6cbebe18 100644 (file)
@@ -4524,3 +4524,45 @@ This analysis tracks the state of the virtual CPUs in conjunction with the physi
 * A way to differentiate between hypervisor mode and normal mode for the virtual CPU. A virtual CPU usually runs within a process on the host, but sometimes that process may need to run hypervisor-specific code. That is called '''hypervisor mode'''. During that time, no code from the guest itself is run. Typically, the process is running on the host (not preempted), but from the guest's point of view, the virtual CPU should be preempted.
 
 A model implementation for a new hypervisor will need to implement class '''IVirtualMachineModel''', that can be found in package '''org.eclipse.tracecompass.internal.lttng2.kernel.core.analysis.vm.model'''. See the javadoc in the class itself for more information on what each method does.
+
+= JUL Logging =
+
+Logging can be quite useful to debug a class, see its interactions with other components and understand the behavior of the system. TraceCompass uses JUL to log various events in the code, which can then be used to model and analyze the system's workflow. Here are some guidelines to use logging efficiently in Trace Compass. See the User Documentation for instructions on how to enable logging and obtain traces.
+
+=== Use a static logger for each class ===
+
+Each class should define and use their own static logger like this:
+
+    private static final Logger LOGGER = TraceCompassLog.getLogger(StateSystem.class);
+
+It is then easy to filter the components to log by their full class name. The ''TraceCompassLog#getLogger'' method is a wrapper for ''java.util.logging.Logger#getLogger'', but the Trace Compass's logging initialization (overriding the default's ConsoleHandler and INFO level for the org.eclipse.tracecompass namespace when logging is not enabled) is done in the static initializer of this class. Using the wrapper method ensures that this code is called and the user will not see Console message all over the place.
+
+'''Note on abstract classes''': It is debatable whether to use a static logger with the abstract class name or a logger with the concrete class's name.
+
+In the former case, logging for this class uses the classes's own namespace, but it is impossible to discriminate logging statement by concrete classes unless the concrete class name is added as parameter to the statement (when necessary).
+
+The latter case has the advantage that one can log only the concrete class and see all that goes on in the abstract class as well, but the concrete class may be in another namespace and will not benefit from the ''TraceCompassLog'' logging initialization and the user will see console logging happen.
+
+Both methods have their advantages and there is no clear good answer.
+
+=== Use a message supplier ===
+
+A logging statement, to be meaningful, will usually log a string that contains data from the context and will thus do string concatenation. This has a non-negligible overhead. To avoid having to do the costly string concatenation when the statement is not logged, java provides method taking a ''Supplier<String>'' as argument and that method should be used for all logging statements
+
+    LOGGER.info(() -> "[Component:Action] param1=" + myParam1 + ", param2=" + myParam2);
+
+=== Choose the appropriate log level ===
+
+The available log levels for JUL are SEVERE, WARNING, INFO, CONFIG, FINE, FINER, FINEST. The default level when not specified is INFO.
+
+* As a rule of thumb, enabling all INFO level statements should have a near zero impact on the execution, so log parameters that require some computations, or methods that are called very often should not be logged at INFO level.
+* CONFIG level should provide more detailed information than the INFO level, but still not impact the execution too much. It should be possible for a component to use up to CONFIG level statements and make meaningful analyses using the timestamps of the events.
+* FINE, FINER and FINEST are for statements that will not be used with the timestamps. Enabling them may have a visible effect on the performance of Trace Compass. They will typically be used with a purpose in mind, like debugging a component or getting data on caches for examples.
+
+=== Log message format ===
+
+JUL logging will produce trace data and unless one wants to visually parse a trace one event at a time, it will typically be used with an analysis to produce a result. To do so, the log messages should have a format that can then be associated with a trace type.
+
+Third party plugins provide a custom trace parser and LTTng trace type for JUL statements that use the following format
+
+    [EventName:MayContainSemiColon] paramName1=paramValue1, paramName2=paramValue2
This page took 0.026655 seconds and 5 git commands to generate.