/* log - a generic logging facility in the spirit of log4j */
-/* Copyright (c) 2003, 2004 Martin Quinson. All rights reserved. */
+/* Copyright (c) 2003-2007 Martin Quinson. All rights reserved. */
/* This program is free software; you can redistribute it and/or modify it
* under the terms of the license (GNU LGPL) which comes with this package. */
#include "xbt/misc.h"
#include "xbt/ex.h"
#include "xbt/sysdep.h"
-#include "xbt/log.h"
+#include "xbt/log_private.h"
#include "xbt/dynar.h"
XBT_PUBLIC_DATA(int) (*xbt_pid)();
- \ref log_API
- \ref log_API_cat
- \ref log_API_pri
+ - \ref log_API_isenabled
- \ref log_API_subcat
- \ref log_API_easy
- \ref log_API_example
- \ref log_user
- \ref log_use_conf
+ - \ref log_use_conf_thres
+ - \ref log_use_conf_multi
+ - \ref log_use_conf_fmt
+ - \ref log_use_conf_add
- \ref log_use_misc
- \ref log_internals
- \ref log_in_perf
as the one able to send the strings to a central server in charge of
syndicating the logs of every distributed daemons on a well known location.
-It should also be possible to pass configuration informations to the appenders,
-specifying for example that the message location (file and line number) is only
-relevant to debugging information, not to critical error messages.
-
One day, for sure ;)
\subsection log_lay 1.4 Message layouts
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.
-
-Here are the existing format directives:
-
- - %%: the % char
- - %n: platform-dependant line separator (LOG4J compliant)
- - %e: plain old space (SimGrid extension)
-
- - %m: user-provided message
-
- - %c: Category name (LOG4J compliant)
- - %p: Priority name (LOG4J compliant)
-
- - %h: Hostname (SimGrid extension)
- - %t: Process name (LOG4J compliant -- thread name in LOG4J)
- - %I: Process PID (SimGrid extension)
-
- - %F: file name where the log event was raised (LOG4J compliant)
- - %l: location where the log event was raised (LOG4J compliant, like '%F:%L')
- - %L: line number where the log event was raised (LOG4J compliant)
- - %M: function name (LOG4J compliant -- called method name here of course).
- Defined only when using gcc because there is no __FUNCTION__ elsewhere.
-
- - %b: full backtrace (Called %throwable in LOG4J).
- Defined only when using the GNU libc because backtrace() is not defined
- elsewhere.
- - %B: short backtrace (only the first line of the %b).
- Called %throwable{short} in LOG4J, defined where %b is.
-
- - %d: date (UNIX epoch)
- - %r: application age (time elapsed since the beginning of the application)
-
-
-If you want to mimick 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] %l: [%c/%p] %m%n' in this
-case). Moreover, if there is no process name (ie, messages comming 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 one format modifyier: the precision field. You can for
-example specify %.4r to get the application age with 4 numbers after the radix.
+and another one allowing users to specify the format they want.
+\ref log_use_conf provides more info on this.
\subsection log_hist 1.5 History of this module
<code>CWARN4(MyCat, "Values are: %d and '%s'", 5, "oops");</code>
-\section log_API_subcat 2.3 Using a default category (the easy interface)
+\section log_API_isenabled 2.3 Checking if a perticular category/priority is enabled
+
+It is sometimes useful to check whether a perticular category is
+enabled at a perticular 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).
+
+\section log_API_subcat 2.4 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>WARN3("Values are: %d and '%s'", 5, "oops");</code>
+<code>WARN3("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.
-\section log_API_easy 2.4 Putting all together: the easy interface
+\section log_API_easy 2.5 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.
the #XBT_IN, XBT_IN<n> (up to #XBT_IN5), #XBT_OUT and #XBT_HERE macros
instead.
-\section log_API_example 2.5 Example of use
+\section log_API_example 2.6 Example of use
Here is a more complete example:
/ * Now set the parent's priority. (the string would typcially be a runtime option) * /
xbt_log_control_set("SA.thresh:3");
- / * This request is enabled, because WARNING >= INFO. * /
+ / * This request is enabled, because WARNING >= INFO. * /
CWARN2(VSS, "Low fuel level.");
- / * This request is disabled, because DEBUG < INFO. * /
+ / * This request is disabled, because DEBUG < INFO. * /
CDEBUG2(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. * /
+ the following request is enabled because INFO >= INFO. * /
INFO1("Located nearest gas station.");
- / * This request is disabled, because DEBUG < INFO. * /
+ / * This request is disabled, because DEBUG < INFO. * /
DEBUG1("Exiting gas station search");
}
\endverbatim
\section log_user 3. User interface
\section log_use_conf 3.1 Configuration
-Configuration is typically done during program initialization by invoking
-the xbt_log_control_set() method. The control string passed to it typically
-comes from the command line. Look at the documentation for that function for
-the format of the control string.
-
-Any SimGrid program can furthermore be configured at run time by passing a
---xbt-log argument on the command line (--gras-log, --msg-log and --surf-log
-are synonyms provided by aestheticism). You can provide several of those
-arguments to change the setting of several categories, they will be applied
-from left to right. So,
-\verbatim --xbt-log="root.thres:debug root.thres:critical"\endverbatim
-should disable any logging.
+Although rarely done, it is possible to configure the logs during
+program initialization by invoking the xbt_log_control_set() method
+manually. A more conventionnal way is to use the --log command line
+argument. xbt_init() (called by MSG_init(), gras_init() and friends)
+checks and deals properly with such arguments.
+
+The following command line arguments exist, but are deprecated and
+may disapear in the future: --xbt-log, --gras-log, --msg-log and
+--surf-log.
+
+\subsection log_use_conf_thres 3.1.1 Thresold configuration
+
+The most common setting is to control which logging event will get
+displayed by setting a threshold to each category through the
+<tt>thres</tt> keyword.
+
+For example, \verbatim --log=root.thres:debug\endverbatim will make
+SimGrid <b>extremely</b> verbose while \verbatim
+--log=root.thres:critical\endverbatim should shut it almost
+completely off.
+
+\subsection log_use_conf_multi 3.1.2 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 --xbt-log=root.thres:debug --xbt-log=root.thres:critical\endverbatim
+\verbatim --log=root.thres:debug --log=root.thres:critical\endverbatim
+
+\subsection log_use_conf_fmt 3.1.3 Format configuration
+
+As with SimGrid 3.3, it is possible to control the format of log
+messages. This is done 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-dependant line separator (LOG4J compliant)
+ - %%e: plain old space (SimGrid extension)
+
+ - %%m: user-provided message
+
+ - %%c: Category name (LOG4J compliant)
+ - %%p: Priority name (LOG4J compliant)
+
+ - %%h: Hostname (SimGrid extension)
+ - %%P: Process name (SimGrid extension)
+ - %%t: Thread "name" (LOG4J compliant -- 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 compliant)
+ - %%l: location where the log event was raised (LOG4J compliant, like '%%F:%%L' -- this is a l as in 'l'etter)
+ - %%L: line number where the log event was raised (LOG4J compliant)
+ - %%M: function name (LOG4J compliant -- called method name here of course).
+ Defined only when using gcc because there is no __FUNCTION__ elsewhere.
+
+ - %%b: full backtrace (Called %%throwable in LOG4J).
+ Defined only when using the GNU libc because backtrace() is not defined
+ elsewhere.
+ - %%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 mimick 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] %%l: [%%c/%%p] %%m%%n' in this
+case). Moreover, if there is no process name (ie, messages comming 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 one format modifyier: the precision field. You
+can for example specify %.4r to get the application age with 4
+numbers after the radix. Another limitation is that you cannot set
+specific layouts to the several priorities.
+
+\subsection log_use_conf_add 3.1.4 Category additivity
+
+The <tt>add</tt> keyword allows to specify the additivity of a
+category (see \ref log_in_app). This is rarely useful since you
+cannot specify an alternative appender. Anyway, '0', '1', 'no',
+'yes', 'on' and 'off' are all valid values, with 'yes' as default.
\section log_use_misc 3.2 Misc and Caveats
\section log_internals 4. Internal considerations
-This module is a mess 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.
+This module is a mess 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...
\section log_in_perf 4.1 Performance
causes all logging requests with a lower priority to be optimized to 0 cost
by the compiler. By setting it to gras_log_priority_infinite, all logging
requests are statically disabled and cost nothing. Released executables
-might be compiled with
+<i>might</i> be compiled with (note that it will prevent users to debug their problems)
\verbatim-DXBT_LOG_STATIC_THRESHOLD=gras_log_priority_infinite\endverbatim
Compiling with the \verbatim-DNLOG\endverbatim option disables all logging
"CRITICAL"
};
-XBT_PUBLIC_DATA(s_xbt_log_category_t) _XBT_LOGV(XBT_LOG_ROOT_CAT) = {
- 0, 0, 0,
- "root", xbt_log_priority_uninitialized, 0,
- NULL, 0
+s_xbt_log_category_t _XBT_LOGV(XBT_LOG_ROOT_CAT) = {
+ NULL /*parent*/, NULL /* firstChild */, NULL /* nextSibling */,
+ "root", xbt_log_priority_uninitialized /* threshold */,
+ 0 /* isThreshInherited */,
+ NULL /* appender */, NULL /* layout */,
+ 0 /* additivity */
};
XBT_LOG_NEW_CATEGORY(xbt,"All XBT categories (simgrid toolbox)");
XBT_LOG_NEW_CATEGORY(surf,"All SURF categories");
XBT_LOG_NEW_CATEGORY(msg,"All MSG categories");
XBT_LOG_NEW_CATEGORY(simix,"All SIMIX categories");
+
XBT_LOG_NEW_DEFAULT_SUBCATEGORY(log,xbt,"Loggings from the logging mechanism itself");
/** @brief Get all logging settings from the command line
xbt_log_default_layout = xbt_log_layout_simple_new(NULL);
_XBT_LOGV(XBT_LOG_ROOT_CAT).appender = xbt_log_default_appender;
_XBT_LOGV(XBT_LOG_ROOT_CAT).layout = xbt_log_default_layout;
- _log_usable = 1;
+ _log_usable = 1;
+
+// _XBT_LOGV(log).threshold = xbt_log_priority_debug; /* uncomment to set the LOG category to debug directly */
/* Set logs and init log submodule */
for (i=1; i<*argc; i++){
xbt_log_category_t cat = ev->cat;
if (!_log_usable) {
- fprintf(stderr,"XXXXXXXXXXXXXXXXXXX\nXXX Warning, logs not usable here. Either before xbt_init() or after xbt_exit().\nXXXXXXXXXXXXXXXXXXX\n");
- va_start(ev->ap, fmt);
- vfprintf(stderr,fmt,ev->ap);
- va_end(ev->ap);
- xbt_backtrace_display();
- return;
+ /* Make sure that the layouts have been malloced */
+ xbt_log_default_appender = xbt_log_appender_file_new(NULL);
+ xbt_log_default_layout = xbt_log_layout_simple_new(NULL);
+ _XBT_LOGV(XBT_LOG_ROOT_CAT).appender = xbt_log_default_appender;
+ _XBT_LOGV(XBT_LOG_ROOT_CAT).layout = xbt_log_default_layout;
+ _log_usable = 1;
}
va_start(ev->ap, fmt);
+ va_start(ev->ap_copy, fmt);
while(1) {
xbt_log_appender_t appender = cat->appender;
if (appender != NULL) {
xbt_assert1(cat->layout,"No valid layout for the appender of category %s",cat->name);
- char *str= cat->layout->do_layout(cat->layout, ev, fmt);
- appender->do_append(appender, str);
+ cat->layout->do_layout(cat->layout, ev, fmt, appender);
}
if (!cat->additivity)
break;
cat = cat->parent;
}
va_end(ev->ap);
+ va_end(ev->ap_copy);
}
static void _xbt_log_cat_apply_set(xbt_log_category_t category,
xbt_log_setting_t setting=NULL;
int found = 0;
s_xbt_log_event_t _log_ev;
-
+
+ if (_XBT_LOGV(log).threshold <= xbt_log_priority_debug
+ && _XBT_LOGV(log).threshold != xbt_log_priority_uninitialized) {
+ _log_ev.cat = &_XBT_LOGV(log);
+ _log_ev.priority = xbt_log_priority_debug;
+ _log_ev.fileName = __FILE__ ;
+ _log_ev.functionName = _XBT_FUNCTION ;
+ _log_ev.lineNum = __LINE__ ;
+ _xbt_log_event_log(&_log_ev, "Initializing category '%s' (firstChild=%s, nextSibling=%s)",
+ category->name,
+ (category->firstChild ?category->firstChild->name :"none"),
+ (category->nextSibling?category->nextSibling->name:"none"));
+ }
+
if(category == &_XBT_LOGV(XBT_LOG_ROOT_CAT)){
category->threshold = xbt_log_priority_info;/* xbt_log_priority_debug*/;
category->appender = xbt_log_default_appender;
if (!category->parent)
category->parent = &_XBT_LOGV(XBT_LOG_ROOT_CAT);
+ if (_XBT_LOGV(log).threshold <= xbt_log_priority_debug
+ && _XBT_LOGV(log).threshold != xbt_log_priority_uninitialized) {
+ _log_ev.lineNum = __LINE__ ;
+ _xbt_log_event_log(&_log_ev, "Set %s (%s) as father of %s ", category->parent->name,
+ (category->parent->threshold == xbt_log_priority_uninitialized ? "uninited":xbt_log_priority_names[category->parent->threshold]),
+ category->name);
+ }
xbt_log_parent_set(category, category->parent);
+
+ if (_XBT_LOGV(log).threshold < xbt_log_priority_info
+ && _XBT_LOGV(log).threshold != xbt_log_priority_uninitialized) {
+ char *buf,*res=NULL;
+ xbt_log_category_t cpp = category->parent->firstChild;
+ while (cpp) {
+ if (res) {
+ buf = bprintf("%s %s",res,cpp->name);
+ free(res);
+ res = buf;
+ } else {
+ res = xbt_strdup(cpp->name);
+ }
+ cpp = cpp->nextSibling;
+ }
+
+ _log_ev.lineNum = __LINE__ ;
+ _xbt_log_event_log(&_log_ev,
+ "Childs of %s: %s; nextSibling: %s", category->parent->name,res,
+ (category->parent->nextSibling?category->parent->nextSibling->name:"none"));
+
+ free(res);
+ }
+
}
/* Apply the control */
if (!found && category->threshold <= xbt_log_priority_verbose) {
- _log_ev.cat = category;
+ _log_ev.cat = &_XBT_LOGV(log);
_log_ev.priority = xbt_log_priority_verbose;
_log_ev.fileName = __FILE__ ;
_log_ev.functionName = _XBT_FUNCTION ;
return priority >= category->threshold;
}
-void xbt_log_parent_set(xbt_log_category_t cat,xbt_log_category_t parent)
-{
+void xbt_log_parent_set(xbt_log_category_t cat,xbt_log_category_t parent) {
xbt_assert0(cat,"NULL category to be given a parent");
xbt_assert1(parent,"The parent category of %s is NULL",cat->name);
}
static xbt_log_category_t _xbt_log_cat_searchsub(xbt_log_category_t cat,char *name) {
- xbt_log_category_t child;
+ xbt_log_category_t child,res;
+ DEBUG4("Search '%s' into '%s' (firstChild='%s'; nextSibling='%s')",name,cat->name,
+ (cat->firstChild ? cat->firstChild->name :"none"),
+ (cat->nextSibling ? cat->nextSibling->name:"none"));
if (!strcmp(cat->name,name))
return cat;
- for(child=cat->firstChild ; child != NULL; child = child->nextSibling)
- return _xbt_log_cat_searchsub(child,name);
-
- THROW1(not_found_error,0,"No such category: %s", name);
+ for (child=cat->firstChild ; child != NULL; child = child->nextSibling) {
+ DEBUG1("Dig into %s",child->name);
+ res = _xbt_log_cat_searchsub(child,name);
+ if (res)
+ return res;
+ }
+
+ return NULL;
}
/**
created), or store it for further use */
xbt_dynar_foreach(set_strings,cpt,str) {
xbt_log_category_t cat=NULL;
- int found=0;
- xbt_ex_t e;
set = _xbt_log_parse_setting(str);
+ cat = _xbt_log_cat_searchsub(&_XBT_LOGV(XBT_LOG_ROOT_CAT),set->catname);
- TRY {
- cat = _xbt_log_cat_searchsub(&_XBT_LOGV(root),set->catname);
- found = 1;
- } CATCH(e) {
- if (e.category != not_found_error)
- RETHROW;
- xbt_ex_free(e);
- found = 0;
- }
-
- if (found) {
+ if (cat) {
DEBUG0("Apply directly");
_xbt_log_cat_apply_set(cat,set);
_free_setting((void*)&set);
