doc/gtut-tour-06-logs.doc

   1 /**
   2 @page GRAS_tut_tour_logs Lesson 6: Logging informations properly
   3
   4 \section GRAS_tut_tour_logs_toc Table of Contents
   5  - \ref GRAS_tut_tour_logs_intro
   6  - \ref GRAS_tut_tour_logs_practice
   7  - \ref GRAS_tut_tour_logs_recap
   8  - \ref GRAS_tut_tour_logs_config
   9
  10 <hr>
  11
  12 \section GRAS_tut_tour_logs_intro Introduction
  13
  14 Let's have another look at the output of the program we came up with in
  15 lesson 5:
  16 \include 05-globals.output
  17
  18 It is a bit difficult to read, isn't it? Indeed, it is hard to identify
  19 which process printed which line. It would be possible to add [server] in
  20 any messages comming from the server and do the same for every process
  21 running. Idealy, we would also add the location at which the message was
  22 generated (using __FILE__ and __LINE__) to help debuging, as well as a
  23 timestamping so that we can still reorder the messages in RL when they get
  24 intermixed (yeah, it happen, and there is not much to do against it).
  25 At the end, each time we would like to print a little "hello" debugging
  26 message, we would have to write 3 lines of arguments to fprintf, which is
  27 not that practical.
  28
  29 That is why there is a support for proper logging in GRAS. Technically
  30 speaking, it is not part of GRAS but of XBT, which is the toolbox on which
  31 the whole SimGrid library is built, but that's the same for us.
  32
  33 This logging library follows the spirit of another one called log4j, which
  34 is more or less the reference in the domain. The original version is for
  35 Java, as the name implies, and there was reimplementation for Python
  36 (log4py), C/C++ (log4c) and so on. Since one of the credo of the GRAS
  37 framework is that we don't want any external dependency to ease the
  38 deployment in grid settings, we reimplemented a version of our own.
  39
  40 One of the strong idea of log4j is that log events get structured to give
  41 the user a fine control at run time of what gets displayed and what don't.
  42 For that, <i>log event</i> are produced into <i>log channels</i> at a given
  43 <i>log priority</i>. Then, you can select the minimal priority an event
  44 should have on a given channel to get displayed.
  45
  46 Then, to keep things managable even when the number of channels increase,
  47 the channels form a tree and properties get inherited from parent channel to
  48 childs. Have a look at the existing channels in SimGrid: \ref XBT_log_cats.
  49 You see that for example, the <tt>gras</tt> channel have 5 subchannels (at
  50 time of writing): <tt>gras_ddt</tt>, <tt>gras_msg</tt>, <tt>gras_timer</tt>,
  51 <tt>gras_trp</tt> and <tt>gras_virtu</tt>. If you open or close the
  52 <tt>gras</tt> channel, it automatically affects all those subchannels (and
  53 their respective subchannels too). Finally, channels are not just open or
  54 closed, but filter messages below a given priority (as we said). The
  55 priorities are defined by type #e_xbt_log_priority_t.
  56
  57 That is all you really need to know about the logs before diving into
  58 practice. If you want more information on that topic, refer to the \ref
  59 XBT_log section, which contains much more information than this page.
  60
  61 \section GRAS_tut_tour_logs_practice Putting logs into action
  62
  63 Enough with theory, let's change our example so that it uses proper
  64 loggings. The first thing to do is to add a new channel in the existing
  65 hierarchy. There is 4 macros to create log channels, depending on the kind
  66 of channel we want:
  67 - XBT_LOG_NEW_CATEGORY(MyCat,desc); Create a new root
  68 - XBT_LOG_NEW_SUBCATEGORY(MyCat, ParentCat,desc); Create a new category being child of the category ParentCat
  69 - XBT_LOG_NEW_DEFAULT_CATEGORY(MyCat,desc); Like XBT_LOG_NEW_CATEGORY, but the new category is the default one in this file
  70 - XBT_LOG_NEW_DEFAULT_SUBCATEGORY(MyCat, ParentCat,desc); Like XBT_LOG_NEW_SUBCATEGORY, but the new category is the default one in this file
  71
  72 What we want here is a root category (it does not belong to any existing
  73 channel, for sure), and we want it to be the default one in our file (of
  74 course, it's the only one).
  75 \dontinclude 06-logs.c
  76 \skip XBT_LOG
  77 \until XBT_LOG
  78
  79 Then, we change any call to fprintf to one of the logging macros. There is a
  80 plenty of them, called &lt;priority&gt;&lt;nb args&gt;, such as #DEBUG10,
  81 which produces a debuging log event onto the default category. You have to
  82 declare the name of arguments as part of the macro name for compatibility
  83 with old compilers not accepting variable number of arguments. Here is a
  84 partial list of the existing macros: #DEBUG10, #VERB6, #INFO8, #WARN6,
  85 #ERROR6 and #CRITICAL6. For each priority, this is the biggest macro (and
  86 the others are not documented for sake of clarity in the relevant document).
  87 Ie, VERB10 does not exist, but VERB0 does exist. I may add more if someone
  88 wants more, but that should be enough for most purposes.
  89
  90 Note also that there is no need to add a '\n' at the end of your format
  91 line, it gets automatically added.
  92
  93 \section GRAS_tut_tour_logs_recap Recapping everything together
  94
  95 Once we changed any fprintf of our code to some of these macros, the program
  96 may read:
  97 \include 06-logs.c
  98
  99 And the output now looks better:
 100 \include 06-logs.output
 101
 102 \section GRAS_tut_tour_logs_config The user side: configuring logs at run time
 103
 104 Once we changed our program to use proper logging, it is naturally possible
 105 to choose at run time what we want to see. For example, if we want more
 106 details about our code, we should do (note that a VERBOSE line appears on
 107 client side):
 108 \include 06-logs.output.verbose
 109
 110 On the contrary, if we want to reduce the amount of logging, we may want to
 111 do: \include 06-logs.output.error
 112
 113 Again, you should refer to the \ref XBT_log section for more information on
 114 how to configure the logs. Or you can proceed with the next lesson, of
 115 course.
 116
 117 Go to \ref GRAS_tut_tour_timers
 118 */