From 8ef0956af17f200ffdb74c19c67395747b6b1db2 Mon Sep 17 00:00:00 2001
From: "Peter D. Barnes, Jr." <barnes26@llnl.gov>
Date: Thu, 12 Dec 2013 14:42:43 -0800
Subject: [PATCH] [Bug 1496] Finish the documentation.

Also amended scratch-simulator so printing the list of log
components works as advertised.
---
 RELEASE_NOTES                 |   1 +
 doc/manual/source/logging.rst | 435 +++++++++++++++++++++++++++-------
 scratch/scratch-simulator.cc  |   3 +
 src/core/model/log.h          |  92 ++++---
 4 files changed, 413 insertions(+), 118 deletions(-)

diff --git a/RELEASE_NOTES b/RELEASE_NOTES
index e72d20d06..09ee648c2 100644
--- a/RELEASE_NOTES
+++ b/RELEASE_NOTES
@@ -47,6 +47,7 @@ New user-visible features
 
 Bugs fixed
 ----------
+- Bug 1496 - Option to print log level in NS_LOG messages, and documentation.
 - Bug 1778 - Implement TapBridge::IsLinkUp() function
 - Bug 1777 - Implement the more direct way of "using" configuration of existing tap interface
 - Bug 1776 - Improve CRC performance for CsmaNetDevice in emulation modes
diff --git a/doc/manual/source/logging.rst b/doc/manual/source/logging.rst
index 014e46ecf..7877e2306 100644
--- a/doc/manual/source/logging.rst
+++ b/doc/manual/source/logging.rst
@@ -22,16 +22,14 @@ the same over time.  Users are cautioned against building simulation output
 frameworks on top of logging code, as the output and the way the output
 is enabled may change over time. 
 
-Logging overview
-****************
+Overview
+********
 
 |ns3| logging statements are typically used to log various program
 execution events, such as the occurrence of simulation events or the
 use of a particular function.
 
-For example, this code snippet is from ``Ipv4L3Protocol::IsDestinationAddress()``:
-
-::
+For example, this code snippet is from ``Ipv4L3Protocol::IsDestinationAddress()``::
 
   if (address == iaddr.GetBroadcast ())
     {
@@ -39,71 +37,33 @@ For example, this code snippet is from ``Ipv4L3Protocol::IsDestinationAddress()`
       return true;
      }
 
-If logging has been enabled for the ``Ipv4L3Protocol`` component at a level
-of ``LOGIC`` or above (see below about logging levels), the statement
+If logging has been enabled for the ``Ipv4L3Protocol`` component at a severity
+of ``LOGIC`` or above (see below about log severity), the statement
 will be printed out; otherwise, it will be suppressed.
 
-Logging levels
-==============
+Enabling Output
+===============
 
-The following levels are defined; each level will enable the levels above
-it, with the ``ALL`` level being most verbose:
-
-#. ``LOG_NONE``:  the default, no logging
-#. ``LOG_ERROR``:  serious error messages only
-#. ``LOG_WARN``:  warning messages
-#. ``LOG_DEBUG``:  for use in debugging
-#. ``LOG_FUNCTION``: function tracing
-#. ``LOG_LOGIC``:  control flow tracing within functions
-#. ``LOG_ALL``:  print everything
-
-A special logging level will cause logging output to unconditionally
-appear on ``std::clog``, regardless of whether the user has explicitly enabled 
-logging.
-This macro, ``NS_LOG_UNCOND()``, can be used like a kind of ``printf()`` in
-your code.  An example can be found in ``scratch/scratch-simulator.cc``:
-
-::
-
-   NS_LOG_UNCOND ("Scratch Simulator");
-
-Logging prefixes
-================
-
-This section still needs documentation; bug 1496 is open on this:
-
-.. sourcecode:: bash
-
-   $ NS_LOG="*=all|prefix_all" ./waf --run scratch-simulator
-   Scratch Simulator
-   ScratchSimulator:main(): [ERROR] error message
-   ScratchSimulator:main(): [WARN] warn message
-   ScratchSimulator:main(): [DEBUG] debug message
-   ScratchSimulator:main(): [INFO] info message
-   ScratchSimulator:main(function)
-   ScratchSimulator:main(): [LOGIC] logic message
-
-Enabling logging output
-=======================
-
-There are two ways that users typically control logging output.  The
-first is by setting an ``NS_LOG`` environment variable; e.g.:
+There are two ways that users typically control log output.  The
+first is by setting the ``NS_LOG`` environment variable; e.g.:
 
 .. sourcecode:: bash
 
    $ NS_LOG="*" ./waf --run first
 
-will run the first tutorial program with all logging output.  This can
-be made more granular by selecting individual components:
+will run the ``first`` tutorial program with all logging output.  (The
+specifics of the ``NS_LOG`` format will be discussed below.)
+
+This can be made more granular by selecting individual components:
 
 .. sourcecode:: bash
 
    $ NS_LOG="Ipv4L3Protocol" ./waf --run first
-  
-The second way to enable this is to use explicit statements in your
-program, such as in the first tutorial program:
 
-::
+The output can be further tailored with prefix options.
+  
+The second way to enable logging is to use explicit statements in your
+program, such as in the ``first`` tutorial program::
    
    int
    main (int argc, char *argv[])
@@ -112,48 +72,357 @@ program, such as in the first tutorial program:
      LogComponentEnable ("UdpEchoServerApplication", LOG_LEVEL_INFO);
      ...
 
-Some helpers have special methods to enable the logging of all components
-in a module (across different compilation units, but logically grouped
-together such as the |ns3| wifi code:
+(The meaning of ``LOG_LEVEL_INFO``, and other possible values,
+will be discussed below.)
 
-::
+``NS_LOG`` Syntax
+=================
+
+The ``NS_LOG`` environment variable contains a list of log components
+and options.  Log components are separated by \`:' characters:
+
+.. sourcecode:: bash
+
+   $ NS_LOG="<log-component>:<log-component>..."
+
+Options for each log component are given as flags after
+each log component:
+
+.. sourcecode:: bash
+
+   $ NS_LOG="<log-component>=<option>|<option>...:<log-component>..."
+
+Options control the severity and level for that component,
+and whether optional information should be included, such as the
+simulation time, simulation node, function name, and the symbolic severity.
+
+Log Components
+==============
+
+Generally a log component refers to a single source code ``.cc`` file,
+and encompasses the entire file.
+
+Some helpers have special methods to enable the logging of all components
+in a module, spanning different compilation units, but logically grouped
+together, such as the |ns3| wifi code::
 
    WifiHelper wifiHelper;
    wifiHelper.EnableLogComponents (); 
 
+The ``NS_LOG`` log component wildcard \`*' will enable all components.
+
+To see what log components are defined, any of these will work:
+
+.. sourcecode:: bash
+
+   $ NS_LOG="print-list" ./waf --run ...
+
+   $ NS_LOG="foo"  # a token not matching any log-component
+
+The first form will print the name and enabled flags for all log components
+which are linked in; try it with ``scratch-simulator``.
+The second form prints all registered log components,
+then exit with an error.
+
+
+Severity and Level Options
+==========================
+
+Individual messages belong to a single "severity class," set by the macro
+creating the message.  In the example above,
+``NS_LOG_LOGIC(..)`` creates the message in the ``LOG_LOGIC`` severity class.
+
+The following severity classes are defined as ``enum`` constants:
+
+================  =====================================
+Severity Class    Meaning
+================  =====================================
+``LOG_NONE``      The default, no logging
+``LOG_ERROR``     Serious error messages only
+``LOG_WARN``      Warning messages
+``LOG_DEBUG``     For use in debugging
+``LOG_INFO``      Informational
+``LOG_FUNCTION``  Function tracing
+``LOG_LOGIC``     Control flow tracing within functions
+================  =====================================
+
+Typically one wants to see messages at a given severity class *and higher*.
+This is done by defining inclusive logging "levels":
+
+======================  ===========================================
+Level                   Meaning
+======================  ===========================================
+``LOG_LEVEL_ERROR``     Only ``LOG_ERROR`` severity class messages.
+``LOG_LEVEL_WARN``      ``LOG_WARN`` and above.
+``LOG_LEVEL_DEBUG``     ``LOG_DEBUG`` and above.
+``LOG_LEVEL_INFO``      ``LOG_INFO`` and above.
+``LOG_LEVEL_FUNCTION``  ``LOG_FUNCTION`` and above.
+``LOG_LEVEL_LOGIC``     ``LOG_LOGIC`` and above.
+``LOG_LEVEL_ALL``       All severity classes.
+``LOG_ALL``             Synonym for ``LOG_LEVEL_ALL``
+======================  ===========================================
+
+The severity class and level options can be given in the ``NS_LOG``
+environment variable by these tokens:
+
+============  =================
+Class         Level
+============  =================
+``error``     ``level_error``
+``warn``      ``level_warn``
+``debug``     ``level_debug``
+``info``      ``level_info``
+``function``  ``level_function``
+``logic``     ``level_logic``
+..            | ``level_all``
+              | ``all``
+              | ``*``
+============  =================
+
+Using a severity class token enables log messages at that severity only.
+For example, ``NS_LOG="*=warn"`` won't output messages with severity ``error``.
+``NS_LOG="*=level_debug"`` will output messages at severity levels
+``debug`` and above.
+
+Severity classes and levels can be combined with the \`|' operator:
+``NS_LOG="*=level_warn|logic"`` will output messages at severity levels
+``error``, ``warn`` and ``logic``.
+
+The ``NS_LOG`` severity level wildcard \`*' and ``all``
+are synonyms for ``level_all``.
+
+For log components merely mentioned in ``NS_LOG``
+
+.. sourcecode:: bash
+
+   $ NS_LOG="<log-component>:..."
+
+the default severity is ``LOG_LEVEL_ALL``.
+
+
+Prefix Options
+==============
+
+A number of prefixes can help identify
+where and when a message originated, and at what severity.
+
+The available prefix options (as ``enum`` constants) are
+
+======================  ===========================================
+Prefix Symbol           Meaning
+======================  ===========================================
+``LOG_PREFIX_FUNC``     Prefix the name of the calling function.
+``LOG_PREFIX_TIME``     Prefix the simulation time.
+``LOG_PREFIX_NODE``     Prefix the node id.
+``LOG_PREFIX_LEVEL``    Prefix the severity level.
+``LOG_PREFIX_ALL``      Enable all prefixes.
+======================  ===========================================
+
+The prefix options are described briefly below.
+
+The options can be given in the ``NS_LOG``
+environment variable by these tokens:
+
+================  =========
+Token             Alternate
+================  =========
+``prefix_func``   ``func``
+``prefix_time``   ``time``
+``prefix_node``   ``node``
+``prefix_level``  ``level``
+``prefix_all``    | ``all``
+                  | ``*``
+================  =========
+
+For log components merely mentioned in ``NS_LOG``
+
+.. sourcecode:: bash
+
+   $ NS_LOG="<log-component>:..."
+
+the default prefix options are ``LOG_PREFIX_ALL``.
+
+Severity Prefix
+###############
+
+The severity class of a message can be included with the options
+``prefix_level`` or ``level``.  For example, this value of ``NS_LOG``
+enables logging for all log components (\`*') and all severity
+classes (``=all``), and prefixes the message with the severity
+class (``|prefix_level``).
+
+.. sourcecode:: bash
+
+   $ NS_LOG="*=all|prefix_level" ./waf --run scratch-simulator
+   Scratch Simulator
+   [ERROR] error message
+   [WARN] warn message
+   [DEBUG] debug message
+   [INFO] info message
+   [FUNCT] function message
+   [LOGIC] logic message
+
+Time Prefix
+###########
+
+The simulation time can be included with the options
+``prefix_time`` or ``time``.  This prints the simulation time in seconds.
+
+Node Prefix
+###########
+
+The simulation node id can be included with the options
+``prefix_node`` or ``node``.
+
+Function Prefix
+###############
+
+The name of the calling function can be included with the options
+``prefix_func`` or ``func``.
+
+
+``NS_LOG`` Wildcards
+####################
+
+The log component wildcard \`*' will enable all components.  To
+enable all components at a specific severity level
+use ``*=<severity>``.
+
+The severity level option wildcard \`*' is a synonym for ``all``.
+This must occur before any \`|' characters separating options.
+To enable all severity classes, use ``<log-component>=*``,
+or ``<log-component>=*|<options>``.
+
+The option wildcard \`*' or token ``all`` enables all prefix options,
+but must occur *after* a \`|' character.  To enable a specific
+severity class or level, and all prefixes, use
+``<log-component>=<severity>|*``.
+
+The combined option wildcard ``**`` enables all severities and all prefixes;
+for example, ``<log-component>=**``.
+
+The uber-wildcard ``***`` enables all severities and all prefixes
+for all log components.  These are all equivalent:
+
+.. sourcecode:: bash
+
+   $ NS_LOG="***" ...      $ NS_LOG="*=all|*" ...        $ NS_LOG="*=*|all" ...	      
+   $ NS_LOG="*=**" ...     $ NS_LOG="*=level_all|*" ...  $ NS_LOG="*=*|prefix_all" ...
+   $ NS_LOG="*=*|*" ...
+                       
+Be advised:  even the trivial ``scratch-simulator`` produces over
+46K lines of output with ``NS_LOG="***"``!
+
 
 How to add logging to your code
 *******************************
 
-To add logging to your code, please follow the below steps:
+Adding logging to your code is very simple:
 
-1) Put ``NS_LOG_COMPONENT_DEFINE`` macro outside of namespace ns3
+1. Invoke the ``NS_LOG_COMPONENT_DEFINE (...);`` macro
+  outside of ``namespace ns3``.
 
-Create a unique string identifier (usually based on the name of the file
-and/or class defined within the file) and register it with a macro call
-such as follows:
+  Create a unique string identifier (usually based on the name of the file
+  and/or class defined within the file) and register it with a macro call
+  such as follows:
 
-::
+  ::
 
-   NS_LOG_COMPONENT_DEFINE ("Ipv4L3Protocol");
+    NS_LOG_COMPONENT_DEFINE ("Ipv4L3Protocol");
 
-   namespace ns3 {
-   ...
+    namespace ns3 {
+    ...
 
-The macro was carefully written to permit inclusion either within or
-outside of namespace ``ns3``, and usage will vary across the codebase, but
-the original intent was to register this *outside* of namespace ``ns3``.
+  This registers ``Ipv4L3Protocol`` as a log component.
+
+  (The macro was carefully written to permit inclusion either within or
+  outside of namespace ``ns3``, and usage will vary across the codebase, but
+  the original intent was to register this *outside* of namespace ``ns3``.)
+
+2. Add logging statements (macro calls) to your functions and function bodies.
+
+Logging Macros
+==============
+
+  The logging macros and associated severity levels are
+
+  ================  ==========================
+  Severity Class    Macro
+  ================  ==========================
+  ``LOG_NONE``      (none needed)
+  ``LOG_ERROR``     ``NS_LOG_ERROR (...);``
+  ``LOG_WARN``      ``NS_LOG_WARN (...);``
+  ``LOG_DEBUG``     ``NS_LOG_DEBUG (...);``
+  ``LOG_INFO``      ``NS_LOG_INFO (...);``
+  ``LOG_FUNCTION``  ``NS_LOG_FUNCTION (...);``
+  ``LOG_LOGIC``     ``NS_LOG_LOGIC (...);``
+  ================  ==========================
+
+  The macros function as output streamers, so anything you can send to
+  ``std::cout``, joined by ``<<`` operators, is allowed::
+
+    void MyClass::Check (int value, char * item)
+    {
+      NS_LOG_FUNCTION (this << arg << item);
+      if (arg > 10)
+        {
+          NS_LOG_ERROR ("encountered bad value " << value <<
+                        " while checking " << name << "!");
+        }
+      ...
+    }
+
+  Note that ``NS_LOG_FUNCTION`` automatically inserts a \`\ :literal:`,\ `'
+  (comma-space) separator between each of its arguments.
+  This simplifies logging of function arguments;
+  just concatenate them with ``<<`` as in the example above.
+
+Unconditional Logging
+=====================
+
+As a convenience, the ``NS_LOG_UNCOND (...);`` macro will always log its
+arguments, even if the associated log-component is not enabled at any
+severity.  This macro does not use any of the prefix options.  Note that
+logging is only enabled in debug builds; this macro won't produce
+output in optimized builds.
+
+
+Guidelines
+==========
+
+* Start every class method with ``NS_LOG_FUNCTION (this << args...);``
+  This enables easy function call tracing.
+
+  * Except:  don't log operators or explicit copy constructors, 
+    since these will cause infinite recursion and stack overflow.
+
+  * For methods without arguments use the same form:
+    ``NS_LOG_FUNCTION (this);``
+
+  * For static functions:
+
+    * With arguments use ``NS_LOG_FUNCTION (...);`` as normal.
+    * Without arguments use ``NS_LOG_FUNCTION_NOARGS ();``
+
+* Use ``NS_LOG_ERROR`` for serious error conditions that probably
+  invalidate the simulation execution.
+
+* Use ``NS_LOG_WARN`` for unusual conditions that may be correctable.
+  Please give some hints as to the nature of the problem and how
+  it might be corrected.
+
+* ``NS_LOG_DEBUG`` is usually used in an *ad hoc* way to understand
+  the execution of a model.
+
+* Use ``NS_LOG_INFO`` for additional information about the execution,
+  such as the size of a data structure when adding/removing from it.
+
+* Use ``NS_LOG_LOGIC`` to trace important logic branches within a function.
+
+* Test that your logging changes do not break the code.  
+  Run some example programs with all log components turned on (e.g. 
+  ``NS_LOG="***"``).
 
-2) Add logging statements to your functions and function bodies.
 
-There are a couple of guidelines on this:
 
-* Do *not* add function logging in operators or explicit copy constructors, 
-  since these will cause infinite recursion and stack overflow.
-* Use the ``NS_LOG_FUNCTION_NOARGS()`` variant for static methods *only*. When 
-  a non-static member function has no arguments, it should be logged by 
-  ``NS_LOG_FUNCTION (this)`` macro.
-* Make sure that you test that your logging changes do not break the code; 
-  running some example programs with all log components turned on (e.g. 
-  ``NS_LOG="*"``) is one way to test this.
 
diff --git a/scratch/scratch-simulator.cc b/scratch/scratch-simulator.cc
index f11de3ccd..c4c039f56 100644
--- a/scratch/scratch-simulator.cc
+++ b/scratch/scratch-simulator.cc
@@ -24,4 +24,7 @@ int
 main (int argc, char *argv[])
 {
   NS_LOG_UNCOND ("Scratch Simulator");
+
+  Simulator::Run ();
+  Simulator::Destroy ();
 }
diff --git a/src/core/model/log.h b/src/core/model/log.h
index 64aa4fba9..c8d1a7f40 100644
--- a/src/core/model/log.h
+++ b/src/core/model/log.h
@@ -28,6 +28,43 @@
 
 namespace ns3 {
 
+/**
+ * \ingroup debugging
+ * \defgroup logging Logging
+ * \brief Logging functions and macros
+ *
+ * LOG functionality: macros which allow developers to
+ * send information to the std::clog output stream. All logging messages 
+ * are disabled by default. To enable selected logging 
+ * messages, use the ns3::LogComponentEnable
+ * function or use the NS_LOG environment variable 
+ *
+ * Use the environment variable NS_LOG to define a ':'-separated list of
+ * logging components to enable. For example (using bash syntax), 
+ * NS_LOG="OlsrAgent" would enable one component at all log levels. 
+ * NS_LOG="OlsrAgent:Ipv4L3Protocol" would enable two components, 
+ * at all log levels, etc.
+ * NS_LOG="*" will enable all available log components at all levels.
+ *
+ * To control more selectively the log levels for each component, use
+ * this syntax: NS_LOG='Component1=func|warn:Component2=error|debug'
+ * This example would enable the 'func', and 'warn' log
+ * levels for 'Component1' and the 'error' and 'debug' log levels
+ * for 'Component2'.  The wildcard can be used here as well.  For example
+ * NS_LOG='*=level_all|prefix' would enable all log levels and prefix all
+ * prints with the component and function names.
+ *
+ * A note on NS_LOG_FUNCTION() and NS_LOG_FUNCTION_NOARGS():
+ * generally, use of (at least) NS_LOG_FUNCTION(this) is preferred.
+ * Use NS_LOG_FUNCTION_NOARGS() only in static functions.
+ */
+
+
+/**
+ *  \ingroup logging
+ *
+ *  Logging severity classes and levels.
+ */
 enum LogLevel {
   LOG_NONE           = 0x00000000, // no logging
 
@@ -134,35 +171,51 @@ void LogComponentDisableAll (enum LogLevel level);
 #define NS_LOG_COMPONENT_DEFINE(name)                           \
   static ns3::LogComponent g_log = ns3::LogComponent (name)
 
+/**
+ * \ingroup logging
+ * Append the simulation time to a log message.
+ */
 #define NS_LOG_APPEND_TIME_PREFIX                               \
   if (g_log.IsEnabled (ns3::LOG_PREFIX_TIME))                   \
     {                                                           \
       ns3::LogTimePrinter printer = ns3::LogGetTimePrinter ();  \
       if (printer != 0)                                         \
         {                                                       \
-          (*printer)(std::clog);                               \
+          (*printer)(std::clog);                                \
           std::clog << " ";                                     \
         }                                                       \
     }
 
+/**
+ * \ingroup logging
+ * Append the simulation node id to a log message.
+ */
 #define NS_LOG_APPEND_NODE_PREFIX                               \
   if (g_log.IsEnabled (ns3::LOG_PREFIX_NODE))                   \
     {                                                           \
       ns3::LogNodePrinter printer = ns3::LogGetNodePrinter ();  \
       if (printer != 0)                                         \
         {                                                       \
-          (*printer)(std::clog);                               \
+          (*printer)(std::clog);                                \
           std::clog << " ";                                     \
         }                                                       \
     }
 
+/**
+ * \ingroup logging
+ * Append the function name to a log message.
+ */
 #define NS_LOG_APPEND_FUNC_PREFIX                               \
   if (g_log.IsEnabled (ns3::LOG_PREFIX_FUNC))                   \
     {                                                           \
       std::clog << g_log.Name () << ":" <<                      \
-      __FUNCTION__ << "(): ";                                 \
+      __FUNCTION__ << "(): ";                                   \
     }                                                           \
 
+/**
+ * \ingroup logging
+ * Append the log severity level to a log message.
+ */
 #define NS_LOG_APPEND_LEVEL_PREFIX(level)                       \
   if (g_log.IsEnabled (ns3::LOG_PREFIX_LEVEL))                  \
     {                                                           \
@@ -179,37 +232,6 @@ void LogComponentDisableAll (enum LogLevel level);
 #ifdef NS3_LOG_ENABLE
 
 
-/**
- * \ingroup debugging
- * \defgroup logging Logging
- * \brief Logging functions and macros
- *
- * LOG functionality: macros which allow developers to
- * send information out on screen. All logging messages 
- * are disabled by default. To enable selected logging 
- * messages, use the ns3::LogComponentEnable
- * function or use the NS_LOG environment variable 
- *
- * Use the environment variable NS_LOG to define a ':'-separated list of
- * logging components to enable. For example (using bash syntax), 
- * NS_LOG="OlsrAgent" would enable one component at all log levels. 
- * NS_LOG="OlsrAgent:Ipv4L3Protocol" would enable two components, 
- * at all log levels, etc.
- * NS_LOG="*" will enable all available log components at all levels.
- *
- * To control more selectively the log levels for each component, use
- * this syntax: NS_LOG='Component1=func|warn:Component2=error|debug'
- * This example would enable the 'func', and 'warn' log
- * levels for 'Component1' and the 'error' and 'debug' log levels
- * for 'Component2'.  The wildcard can be used here as well.  For example
- * NS_LOG='*=level_all|prefix' would enable all log levels and prefix all
- * prints with the component and function names.
- *
- * A note on NS_LOG_FUNCTION() and NS_LOG_FUNCTION_NOARGS():
- * generally, use of (at least) NS_LOG_FUNCTION(this) is preferred.
- * Use NS_LOG_FUNCTION_NOARGS() only in static functions.
- */
-
 
 /**
  * \ingroup logging
@@ -330,7 +352,7 @@ void LogComponentDisableAll (enum LogLevel level);
           NS_LOG_APPEND_CONTEXT;                                \
           std::clog << g_log.Name () << ":"                     \
                     << __FUNCTION__ << "(";                     \
-          ns3::ParameterLogger (std::clog) << parameters;      \
+          ns3::ParameterLogger (std::clog) << parameters;       \
           std::clog << ")" << std::endl;                        \
         }                                                       \
     }                                                           \