Logo AND Algorithmique Numérique Distribuée

Public GIT Repository
Merge branch 'master' of scm.gforge.inria.fr:/gitroot/simgrid/simgrid
[simgrid.git] / doc / doxygen / outcomes_logs.doc
index 3dd66c0..669b0e6 100644 (file)
@@ -1,6 +1,441 @@
 /**
 @page outcomes_logs Simulation Logging
+@brief Log4J-like logging system.
 
-TBD
+Using @c printf or @c println to display information is possible, but
+quickly unpractical, as the logs of all processes get intermixed in
+your program's output. %As an answer, the SimGrid logging module allow
+you to sort and filter the logs by emitter, by module and by gravity
+level. 
+
+The SimGrid logging module is highly <b>configurable</b>: as in Log4J,
+the user can choose <i>at runtime</i> what messages to show and what
+to hide, as well as how messages get displayed. It is also <b>easy to
+use</b>, both to the programmer (using preprocessor macros black
+magic) and to the user (with command line options). And finally, its
+<b>performance</b> is highly optimized.
+
+@tableofcontents
+
+@section log_overview Main Concepts
+
+There is three main concepts in SimGrid's logging mechanism:
+** **category**, **priority** and **appender**. These three concepts work
+together to enable developers to log messages according to message
+type and priority, and to control at runtime how these messages are
+formatted and where they are reported.
+
+@subsection log_cat Logging categories
+
+In SimGrid, the logs are sorted by topics (called categories) so that
+the user can chose which topics to display and hide at runtime. These
+categories are organized as a hierarchy, following the architecture of
+modules in the simulator.
+
+The full list of all categories that exist in the SimGrid base library 
+@ref XBT_log_cats "is available in the documentation".
+You can also provide ```--help-logs``` on the command line of any
+SimGrid simulator to see the list of all existing categories that it
+contains.
+
+@subsection log_pri Logging priorities
+
+The user can also specify the desired level of details for each category. This is
+controlled by the <i>priority</i> concept (which should maybe be renamed to
+<i>severity</i>). For example, you may want to see every debugging message
+of MSG while only being interested into the messages at level "error" or
+higher about the XBT internals.
+
+@subsection log_app Message appenders
+
+The message appenders are in charge of actually displaying the
+message to the user. For now, four appenders exist: 
+- the default one prints stuff on stderr 
+- file sends the data to a single file
+- rollfile overwrites the file when the file grows too large
+- splitfile creates new files with a specific maximum size
+
+@subsection log_lay Message layouts
+
+The message layouts are the elements in charge of choosing how each message
+will look like. Their result is a string which is then passed to the appender
+attached to the category to be displayed.
+
+For now, there is two layouts: The simple one, which is good for most cases,
+and another one allowing users to specify the format they want.
+@ref log_use_conf provides more info on this.
+
+@subsection log_hist History of this module
+
+Historically, this module is an adaptation of the log4c project, which is dead
+upstream, and which I was given the permission to fork under the LGPL licence
+by the log4c's authors. The log4c project itself was loosely based on the
+Apache project's Log4J, which also inspired Log4CC, Log4py and so on. Our work
+differs somehow from these projects anyway, because the C programming language
+is not object oriented.
+
+@section log_API C Programmer interface
+
+Please also refer to the @ref XBT_log "full API" for more information.
+
+@subsection log_API_cat Constructing the category hierarchy
+
+Every category is declared by providing a name and an optional
+parent. If no parent is explicitly named, the root category, LOG_ROOT_CAT is
+the category's parent.
+
+A category is created by a macro call at the top level of a file.  A
+category can be created with any one of the following macros:
+
+ - @ref XBT_LOG_NEW_CATEGORY(MyCat,desc); Create a new root
+ - @ref XBT_LOG_NEW_SUBCATEGORY(MyCat, ParentCat,desc);
+    Create a new category being child of the category ParentCat
+ - @ref XBT_LOG_NEW_DEFAULT_CATEGORY(MyCat,desc);
+    Like XBT_LOG_NEW_CATEGORY, but the new category is the default one
+      in this file
+ -  @ref XBT_LOG_NEW_DEFAULT_SUBCATEGORY(MyCat, ParentCat,desc);
+    Like XBT_LOG_NEW_SUBCATEGORY, but the new category is the default one
+      in this file
+
+The parent cat can be defined in the same file or in another file (in
+which case you want to use the @ref XBT_LOG_EXTERNAL_CATEGORY macro to make
+it visible in the current file), but each category may have only one
+definition. Likewise, you can use a category defined in another file as 
+default one using @ref XBT_LOG_EXTERNAL_DEFAULT_CATEGORY
+
+Typically, there will be a Category for each module and sub-module, so you
+can independently control logging for each module.
+
+For a list of all existing categories, please refer to the @ref XBT_log_cats
+section. This file is generated automatically from the SimGrid source code, so
+it should be complete and accurate. 
+Also refer to the @ref XBT_log "full API" for more information. 
+
+@subsection log_API_pri Declaring message priority
+
+A category may be assigned a threshold priority. The set of priorities are
+defined by the @ref e_xbt_log_priority_t enum. All logging request under
+this priority will be discarded.
+
+If a given category is not assigned a threshold priority, then it inherits
+one from its closest ancestor with an assigned threshold. To ensure that all
+categories can eventually inherit a threshold, the root category always has
+an assigned threshold priority.
+
+Logging requests are made by invoking a logging macro on a category.  All of
+the macros have a printf-style format string followed by arguments. If you
+compile with the -Wall option, gcc will warn you for unmatched arguments, ie
+when you pass a pointer to a string where an integer was specified by the
+format. This is usually a good idea.
+
+Here is an example of the most basic type of macro. This is a logging
+request with priority <i>warning</i>.
+
+<code>XBT_CLOG(MyCat, xbt_log_priority_warning, "Values are: %d and '%s'", 5,
+"oops");</code>
+
+A logging request is said to be enabled if its priority is higher than or
+equal to the threshold priority of its category. Otherwise, the request is
+said to be disabled. A category without an assigned priority will inherit
+one from the hierarchy.
+
+It is possible to use any non-negative integer as a priority. If, as in the
+example, one of the standard priorities is used, then there is a convenience
+macro that is typically used instead. For example, the above example is
+equivalent to the shorter:
+
+<code>XBT_CWARN(MyCat, "Values are: %d and '%s'", 5, "oops");</code>
+
+@subsection log_API_isenabled Checking if a particular category/priority is enabled
+
+It is sometimes useful to check whether a particular category is
+enabled at a particular priority. One example is when you want to do
+some extra computation to prepare a nice debugging message. There is
+no use of doing so if the message won't be used afterward because
+debugging is turned off.
+
+Doing so is extremely easy, thanks to the XBT_LOG_ISENABLED(category, priority).
+
+@subsection log_API_subcat Using a default category (the easy interface)
+
+If @ref XBT_LOG_NEW_DEFAULT_SUBCATEGORY(MyCat, Parent) or
+@ref XBT_LOG_NEW_DEFAULT_CATEGORY(MyCat) is used to create the
+category, then the even shorter form can be used:
+
+<code>XBT_WARN("Values are: %s and '%d'", 5, "oops");</code>
+
+Only one default category can be created per file, though multiple
+non-defaults can be created and used.
+
+@subsection log_API_easy Putting all together: the easy interface
+
+First of all, each module should register its own category into the categories
+tree using @ref XBT_LOG_NEW_DEFAULT_SUBCATEGORY.
+
+Then, logging should be done with the #XBT_DEBUG, #XBT_VERB, #XBT_INFO,
+#XBT_WARN, #XBT_ERROR and #XBT_CRITICAL macros.
+
+Under GCC, these macro check there arguments the same way than printf does. So,
+if you compile with -Wall, the following code will issue a warning:
+<code>XBT_DEBUG("Found %s (id %d)", some_string, a_double)</code>
+
+If you want to specify the category to log onto (for example because you
+have more than one category per file, add a C before the name of the log
+producing macro (ie, use #XBT_CDEBUG, #XBT_CVERB, #XBT_CINFO, #XBT_CWARN,
+#XBT_CERROR and #XBT_CCRITICAL and friends), and pass the category name as
+first argument.
+
+The TRACE priority is not used the same way than the other. You should use
+the #XBT_IN, #XBT_OUT and #XBT_HERE macros instead.
+
+@subsection log_API_example Example of use
+
+Here is a more complete example:
+
+@verbatim
+#include "xbt/log.h"
+
+/ * create a category and a default subcategory * /
+XBT_LOG_NEW_CATEGORY(VSS);
+XBT_LOG_NEW_DEFAULT_SUBCATEGORY(SA, VSS);
+
+int main() {
+       / * Now set the parent's priority.  (the string would typically be a runtime option) * /
+       xbt_log_control_set("SA.thresh:3");
+
+       / * This request is enabled, because WARNING >= INFO. * /
+       XBT_CWARN(VSS, "Low fuel level.");
+
+       / * This request is disabled, because DEBUG < INFO. * /
+       XBT_CDEBUG(VSS, "Starting search for nearest gas station.");
+
+       / * The default category SA inherits its priority from VSS. Thus,
+          the following request is enabled because INFO >= INFO.  * /
+       XBT_INFO("Located nearest gas station.");
+
+       / * This request is disabled, because DEBUG < INFO. * /
+       XBT_DEBUG("Exiting gas station search");
+}
+@endverbatim
+
+Please also refer to the @ref XBT_log "full API" for more information.
+
+@section log_user User interface
+
+@subsection log_use_conf Configuration
+
+Although rarely done, it is possible to configure the logs during
+program initialization by invoking the xbt_log_control_set() method
+manually. A more conventional way is to use the --log command line
+argument. xbt_init() (called by MSG_init() and friends)
+checks and deals properly with such arguments.
+
+@subsubsection log_use_conf_thres Threshold configuration
+
+The most common setting is to control which logging event will get
+displayed by setting a threshold to each category through the
+<tt>threshold</tt> keyword.
+
+For example, @verbatim --log=root.threshold:debug@endverbatim will make
+SimGrid <b>extremely</b> verbose while @verbatim
+--log=root.thres:critical@endverbatim should shut it almost
+completely off.
+
+Note that the <tt>threshold</tt> keyword can be abbreviated here. For example,
+all the following notations have the same result.
+@verbatim
+--log=root.threshold:debug
+--log=root.threshol:debug
+--log=root.thresho:debug
+--log=root.thresh:debug
+--log=root.thres:debug
+--log=root.thre:debug
+--log=root.thr:debug
+--log=root.th:debug
+--log=root.t:debug
+--log=root.:debug     <--- That's obviously really ugly, but it actually works.
+@endverbatim
+
+The full list of recognized thresholds is the following:
+
+ - trace: enter and return of some functions
+ - debug: crufty output
+ - verbose: verbose output for the user wanting more
+ - info: output about the regular functionning
+ - warning: minor issue encountered
+ - error: issue encountered
+ - critical: major issue encountered 
+
+@subsubsection log_use_conf_multi Passing several settings
+
+You can provide several of those arguments to change the setting of several
+categories, they will be applied from left to right. So,
+@verbatim --log="root.thres:debug root.thres:critical"@endverbatim should
+disable almost any logging.
+
+Note that the quotes on above line are mandatory because there is a space in
+the argument, so we are protecting ourselves from the shell, not from SimGrid.
+We could also reach the same effect with this:
+@verbatim --log=root.thres:debug --log=root.thres:critical@endverbatim
+
+@subsubsection log_use_conf_fmt Format configuration
+
+You can control the format of log messages through the <tt>fmt</tt>
+keyword. For example, @verbatim --log=root.fmt:%m@endverbatim reduces
+the output to the user-message only, removing any decoration such as
+the date, or the process ID, everything.
+
+Here are the existing format directives:
+
+ - %%: the % char
+ - %%n: platform-dependent line separator (LOG4J compatible)
+ - %%e: plain old space (SimGrid extension)
+
+ - %%m: user-provided message
+
+ - %%c: Category name (LOG4J compatible)
+ - %%p: Priority name (LOG4J compatible)
+
+ - %%h: Hostname (SimGrid extension)
+ - %%P: Process name (SimGrid extension -- note that with SMPI this is the integer value of the process rank)
+ - %%t: Thread "name" (LOG4J compatible -- actually the address of the thread in memory)
+ - %%i: Process PID (SimGrid extension -- this is a 'i' as in 'i'dea)
+
+ - %%F: file name where the log event was raised (LOG4J compatible)
+ - %%l: location where the log event was raised (LOG4J compatible, like '%%F:%%L' -- this is a l as in 'l'etter)
+ - %%L: line number where the log event was raised (LOG4J compatible)
+ - %%M: function name (LOG4J compatible -- called method name here of course).
+
+ - %%b: full backtrace (Called %%throwable in LOG4J).
+   Defined only under windows or when using the GNU libc because backtrace() is not defined
+   elsewhere, and we only have a fallback for windows boxes, not mac ones for example.
+ - %%B: short backtrace (only the first line of the %%b).
+   Called %%throwable{short} in LOG4J; defined where %%b is.
+
+ - %%d: date (UNIX-like epoch)
+ - %%r: application age (time elapsed since the beginning of the application)
+
+
+If you want to mimic the simple layout with the format one, you would use this
+format: '[%%h:%%i:(%%i) %%r] %%l: [%%c/%%p] %%m%%n'. This is not completely correct
+because the simple layout do not display the message location for messages at
+priority INFO (thus, the fmt is '[%%h:%%i:(%%i) %%r] [%%c/%%p] %%m%%n' in this
+case). Moreover, if there is no process name (ie, messages coming from the
+library itself, or test programs doing strange things) do not display the
+process identity (thus, fmt is '[%%r] %%l: [%%c/%%p] %%m%%n' in that case, and '[%%r]
+[%%c/%%p] %%m%%n' if they are at priority INFO).
+
+For now, there is only two format modifiers: the precision and the
+width fields. You can for example specify %.4r to get the application
+age with 4 numbers after the radix, or %15p to get the process name
+on 15 columns. Finally, you can specify %10.6r to get the time on at
+most 10 columns, with 6 numbers after the radix. 
+
+Note that when specifying the width, it is filled with spaces. That
+is to say that for example %5r in your format is converted to "% 5f"
+for printf (note the extra space); there is no way to fill the empty
+columns with 0 (ie, pass "%05f" to printf). Another limitation is
+that you cannot set specific layouts to the several priorities.
+
+@subsubsection log_use_conf_app Category appender
+
+You can control the appender of log messages through the <tt>app</tt>
+keyword. For example, 
+@verbatim --log=root.app:file:mylogfile@endverbatim redirects the
+output to the file mylogfile.
+
+For splitfile appender, the format is 
+@verbatim --log=root.app:splitfile:size:mylogfile_%.format@endverbatim
+
+The size is in bytes, and the % wildcard will be replaced by the number of the
+file. If no % is present, it will be appended at the end.
+
+rollfile appender is also available, it can be used as
+@verbatim --log=root.app:rollfile:size:mylogfile@endverbatim
+When the file grows to be larger than the size, it will be emptied and new log 
+events will be sent at its beginning 
+
+Any appender setup this way have its own layout format (simple one by default),
+so you may have to change it too afterward. Moreover, the additivity of the log category
+is also set to false to prevent log event displayed by this appender to "leak" to any other
+appender higher in the hierarchy. If it is not what you wanted, you can naturally change it
+manually.
+
+@subsubsection log_use_conf_add Category additivity
+
+The <tt>add</tt> keyword allows to specify the additivity of a
+category (see @ref log_in_app). '0', '1', 'no', 'yes', 'on'
+and 'off' are all valid values, with 'yes' as default.
+
+The following example resets the additivity of the xbt category to true (which is its default value).
+@verbatim --log=xbt.add:yes@endverbatim
+
+@subsection log_use_misc Misc and Caveats
+
+  - Do not use any of the macros that start with '_'.
+  - Log4J has a 'rolling file appender' which you can select with a run-time
+    option and specify the max file size. This would be a nice default for
+    non-kernel applications.
+  - Careful, category names are global variables.
+  - When writing a log format, you often want to use spaces. If you don't
+    protect these spaces, they are used as configuration elements separators.
+    For example, if you want to remove the date from the logs, you want to pass the following 
+    argument on the command line. The outer quotes are here to protect the string from the shell 
+    interpretation while the inner ones are there to prevent simgrid from splitting the string 
+    in several log parameters (that would be invalid).
+    @verbatim --log="'root.fmt:%l: [%p/%c]: %m%n'"@endverbatim
+    Another option is to use the SimGrid-specific format directive \%e for
+    spaces, like in the following.
+    @verbatim --log="root.fmt:%l:%e[%p/%c]:%e%m%n"@endverbatim
+
+@section log_internals Internal considerations
+
+This module is loaded of macro black magic, and when it goes wrong,
+SimGrid studently loose its ability to explain its problems. When
+messing around this module, I often find useful to define
+XBT_LOG_MAYDAY (which turns it back to good old printf) for the time
+of finding what's going wrong. But things are quite verbose when
+everything is enabled...
+
+@subsection log_in_perf Performance
+
+Except for the first invocation of a given category, a disabled logging request
+requires an a single comparison of a static variable to a constant.
+
+There is also compile time constant, @ref XBT_LOG_STATIC_THRESHOLD, which
+causes all logging requests with a lower priority to be optimized to 0 cost
+by the compiler. By setting it to xbt_log_priority_infinite, all logging
+requests are statically disabled at compile time and cost nothing. Released executables
+<i>might</i>  be compiled with (note that it will prevent users to debug their problems)
+@verbatim-DXBT_LOG_STATIC_THRESHOLD=xbt_log_priority_infinite@endverbatim
+
+Compiling with the @verbatim-DNLOG@endverbatim option disables all logging
+requests at compilation time while the @verbatim-DNDEBUG@endverbatim disables
+the requests of priority below INFO.
+
+@todo Logging performance *may* be improved further by improving the message
+propagation from appender to appender in the category tree.
+
+@subsection log_in_app Appenders
+
+Each category has an optional appender. An appender is a pointer to a
+structure which starts with a pointer to a do_append() function. do_append()
+prints a message to a log.
+
+When a category is passed a message by one of the logging macros, the category performs the following actions:
+
+  - if the category has an appender, the message is passed to the
+    appender's do_append() function,
+  - if additivity is true for the category, the message is passed to
+    the category's parent. Additivity is true by default, and can be
+    controlled by xbt_log_additivity_set() or something like --log=root.add:1 (see @ref log_use_conf_add).
+    Also, when you add an appender to a category, its additivity is automatically turned to off.
+    Turn it back on afterward if it is not what you wanted.
+
+By default, only the root category have an appender, and any other category has
+its additivity set to true. This causes all messages to be logged by the root
+category's appender.
+
+The default appender function currently prints to stderr.
 
 */
\ No newline at end of file