X-Git-Url: http://info.iut-bm.univ-fcomte.fr/pub/gitweb/simgrid.git/blobdiff_plain/8de7a90b044d2c8cf008e498f533cd7131c9f106..428d2a22ebffacc0623193ad65defde27e6e7bc6:/doc/doxygen/outcomes_logs.doc diff --git a/doc/doxygen/outcomes_logs.doc b/doc/doxygen/outcomes_logs.doc index 3dd66c0408..131fe3655f 100644 --- a/doc/doxygen/outcomes_logs.doc +++ b/doc/doxygen/outcomes_logs.doc @@ -1,6 +1,435 @@ /** @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 configurable: as in Log4J, +the user can choose at runtime what messages to show and what +to hide, as well as how messages get displayed. It is also easy to +use, both to the programmer (using preprocessor macros black +magic) and to the user (with command line options). And finally, its +performance 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 priority concept (which should maybe be renamed to +severity). 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 warning. + +XBT_CLOG(MyCat, xbt_log_priority_warning, "Values are: %d and '%s'", 5, +"oops"); + +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: + +XBT_CWARN(MyCat, "Values are: %d and '%s'", 5, "oops"); + +@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: + +XBT_WARN("Values are: %s and '%d'", 5, "oops"); + +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: +XBT_DEBUG("Found %s (id %d)", some_string, a_double) + +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 +threshold keyword. + +For example, @verbatim --log=root.threshold:debug@endverbatim will make +SimGrid extremely verbose while @verbatim +--log=root.thres:critical@endverbatim should shut it almost +completely off. + +Note that the threshold 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 fmt +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). + + - %%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 app +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 add 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 +might 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