F5/unison
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

core: (fixes #905) Move log severity class 'debug' below 'logic'

Browse Source
This commit is contained in:
Tom Henderson
2023-05-30 11:13:33 -07:00
parent a959eea3d5
commit b23e65c2bb
4 changed files with 81 additions and 52 deletions
Download Patch File Download Diff File Expand all files Collapse all files

1
CHANGES.md
View File

@@ -76,6 +76,7 @@ Changes from ns-3.38 to ns-3-dev
### Changed behavior ### Changed behavior
* (core) The priority of `DEBUG` level logging has been lowered from just below `WARN` level to just below `LOGIC` level.
* (buildings) Calculation of the O2I Low/High Building Penetration Losses based on 3GPP 38.901 7.4.3.1 was missing. These losses are now included in the pathloss calculation when buildings are present. * (buildings) Calculation of the O2I Low/High Building Penetration Losses based on 3GPP 38.901 7.4.3.1 was missing. These losses are now included in the pathloss calculation when buildings are present.
* (network) The function `Buffer::Allocate` will over-provision `ALLOC_OVER_PROVISION` bytes when allocating buffers for packets. `ALLOC_OVER_PROVISION` is currently set to 100 bytes. * (network) The function `Buffer::Allocate` will over-provision `ALLOC_OVER_PROVISION` bytes when allocating buffers for packets. `ALLOC_OVER_PROVISION` is currently set to 100 bytes.
* (wifi) By default, the `SpectrumWifiHelper` now adds a `WifiBandwidthFilter` to discard out-of-band signals before scheduling them on the receiver. This should not affect the simulated behavior of Wi-Fi but may speed up the execution of large Wi-Fi simulations. * (wifi) By default, the `SpectrumWifiHelper` now adds a `WifiBandwidthFilter` to discard out-of-band signals before scheduling them on the receiver. This should not affect the simulated behavior of Wi-Fi but may speed up the execution of large Wi-Fi simulations.

96
doc/manual/source/logging-asserts.rst
View File

@@ -14,8 +14,8 @@ The |ns3| logging facility can be used to monitor or debug the progress
of simulation programs. Logging output can be enabled by program statements of simulation programs. Logging output can be enabled by program statements
in your ``main()`` program or by the use of the ``NS_LOG`` environment variable. in your ``main()`` program or by the use of the ``NS_LOG`` environment variable.
Logging statements are not compiled into optimized builds of |ns3|. To use Logging statements are not compiled into ``optimized`` builds of |ns3|. To use
logging, one must build the (default) debug build of |ns3|. logging, one must use the ``default`` or ``debug`` build profiles of |ns3|.
The project makes no guarantee about whether logging output will remain The project makes no guarantee about whether logging output will remain
the same over time. Users are cautioned against building simulation output the same over time. Users are cautioned against building simulation output
@@ -29,21 +29,20 @@ Overview
execution events, such as the occurrence of simulation events or the execution events, such as the occurrence of simulation events or the
use of a particular function. use of a particular function.
For example, this code snippet is from ``Ipv4L3Protocol::IsDestinationAddress()``:: For example, this code snippet is from ``TcpSocketBase::EnterCwr()`` and informs the user that
the model is reducing the congestion window and changing state::
if (address == iaddr.GetBroadcast()) NS_LOG_INFO("Enter CWR recovery mode; set cwnd to " << m_tcb->m_cWnd << ", ssthresh to "
{ << m_tcb->m_ssThresh << ", recover to "
NS_LOG_LOGIC("For me (interface broadcast address)"); << m_recover);
return true;
}
If logging has been enabled for the ``Ipv4L3Protocol`` component at a severity If logging has been enabled for the ``Ipv4L3Protocol`` component at a severity
of ``LOGIC`` or above (see below about log severity), the statement of ``INFO`` or above (see below about log severity), the statement
will be printed out; otherwise, it will be suppressed. will be printed out; otherwise, it will be suppressed.
The logging implementation is enabled in ``debug`` and ``default`` The logging implementation is enabled in ``debug`` and ``default``
builds, but disabled in all other build profiles, builds, but disabled in all other build profiles,
so has no impact of execution speed. so that it does not impact the execution speed of more optimized profiles.
You can try the example program `log-example.cc` in `src/core/example` You can try the example program `log-example.cc` in `src/core/example`
with various values for the `NS_LOG` environment variable to see the with various values for the `NS_LOG` environment variable to see the
@@ -138,21 +137,21 @@ Severity and Level Options
Individual messages belong to a single "severity class," set by the macro Individual messages belong to a single "severity class," set by the macro
creating the message. In the example above, creating the message. In the example above,
``NS_LOG_LOGIC(..)`` creates the message in the ``LOG_LOGIC`` severity class. ``NS_LOG_INFO(..)`` creates the message in the ``LOG_INFO`` severity class.
The following severity classes are defined as ``enum`` constants: The following severity classes are defined as ``enum`` constants:
================ ===================================== ================ =========================================================
Severity Class Meaning Severity Class Meaning
================ ===================================== ================ =========================================================
``LOG_NONE`` The default, no logging ``LOG_NONE`` The default, no logging
``LOG_ERROR`` Serious error messages only ``LOG_ERROR`` Serious error messages only
``LOG_WARN`` Warning messages ``LOG_WARN`` Warning messages
``LOG_DEBUG`` For use in debugging ``LOG_INFO`` Info about the model changing state
``LOG_INFO`` Informational
``LOG_FUNCTION`` Function tracing ``LOG_FUNCTION`` Function tracing
``LOG_LOGIC`` Control flow tracing within functions ``LOG_LOGIC`` For tracing key decision points or branches in a function
================ ===================================== ``LOG_DEBUG`` For use in debugging
================ =========================================================
Typically one wants to see messages at a given severity class *and higher*. Typically one wants to see messages at a given severity class *and higher*.
This is done by defining inclusive logging "levels": This is done by defining inclusive logging "levels":
@@ -162,10 +161,10 @@ Level Meaning
====================== =========================================== ====================== ===========================================
``LOG_LEVEL_ERROR`` Only ``LOG_ERROR`` severity class messages. ``LOG_LEVEL_ERROR`` Only ``LOG_ERROR`` severity class messages.
``LOG_LEVEL_WARN`` ``LOG_WARN`` and above. ``LOG_LEVEL_WARN`` ``LOG_WARN`` and above.
``LOG_LEVEL_DEBUG`` ``LOG_DEBUG`` and above.
``LOG_LEVEL_INFO`` ``LOG_INFO`` and above. ``LOG_LEVEL_INFO`` ``LOG_INFO`` and above.
``LOG_LEVEL_FUNCTION`` ``LOG_FUNCTION`` and above. ``LOG_LEVEL_FUNCTION`` ``LOG_FUNCTION`` and above.
``LOG_LEVEL_LOGIC`` ``LOG_LOGIC`` and above. ``LOG_LEVEL_LOGIC`` ``LOG_LOGIC`` and above.
``LOG_LEVEL_DEBUG`` ``LOG_DEBUG`` and above.
``LOG_LEVEL_ALL`` All severity classes. ``LOG_LEVEL_ALL`` All severity classes.
``LOG_ALL`` Synonym for ``LOG_LEVEL_ALL`` ``LOG_ALL`` Synonym for ``LOG_LEVEL_ALL``
====================== =========================================== ====================== ===========================================
@@ -178,10 +177,10 @@ Class Level
============ ================= ============ =================
``error`` ``level_error`` ``error`` ``level_error``
``warn`` ``level_warn`` ``warn`` ``level_warn``
``debug`` ``level_debug``
``info`` ``level_info`` ``info`` ``level_info``
``function`` ``level_function`` ``function`` ``level_function``
``logic`` ``level_logic`` ``logic`` ``level_logic``
``debug`` ``level_debug``
.. | ``level_all`` .. | ``level_all``
| ``all`` | ``all``
| ``*`` | ``*``
@@ -193,8 +192,8 @@ For example, ``NS_LOG="*=warn"`` won't output messages with severity ``error``.
``debug`` and above. ``debug`` and above.
Severity classes and levels can be combined with the \`|' operator: Severity classes and levels can be combined with the \`|' operator:
``NS_LOG="*=level_warn|logic"`` will output messages at severity levels ``NS_LOG="*=level_warn|debug"`` will output messages at severity levels
``error``, ``warn`` and ``logic``. ``error``, ``warn`` and ``debug``, but not ``info``, ``function``, or ``logic``.
The ``NS_LOG`` severity level wildcard \`*' and ``all`` The ``NS_LOG`` severity level wildcard \`*' and ``all``
are synonyms for ``level_all``. are synonyms for ``level_all``.
@@ -265,10 +264,10 @@ class (``|prefix_level``).
Scratch Simulator Scratch Simulator
[ERROR] error message [ERROR] error message
[WARN] warn message [WARN] warn message
[DEBUG] debug message
[INFO] info message [INFO] info message
[FUNCT] function message [FUNCT] function message
[LOGIC] logic message [LOGIC] logic message
[DEBUG] debug message
Time Prefix Time Prefix
########### ###########
@@ -415,10 +414,10 @@ Logging Macros
``LOG_NONE`` (none needed) ``LOG_NONE`` (none needed)
``LOG_ERROR`` ``NS_LOG_ERROR(...);`` ``LOG_ERROR`` ``NS_LOG_ERROR(...);``
``LOG_WARN`` ``NS_LOG_WARN(...);`` ``LOG_WARN`` ``NS_LOG_WARN(...);``
``LOG_DEBUG`` ``NS_LOG_DEBUG(...);``
``LOG_INFO`` ``NS_LOG_INFO(...);`` ``LOG_INFO`` ``NS_LOG_INFO(...);``
``LOG_FUNCTION`` ``NS_LOG_FUNCTION(...);`` ``LOG_FUNCTION`` ``NS_LOG_FUNCTION(...);``
``LOG_LOGIC`` ``NS_LOG_LOGIC(...);`` ``LOG_LOGIC`` ``NS_LOG_LOGIC(...);``
``LOG_DEBUG`` ``NS_LOG_DEBUG(...);``
================ ========================== ================ ==========================
The macros function as output streamers, so anything you can send to The macros function as output streamers, so anything you can send to
@@ -449,15 +448,21 @@ severity. This macro does not use any of the prefix options. Recall
that logging is only enabled in ``debug``, ``default`` and ``relwithdebinfo`` that logging is only enabled in ``debug``, ``default`` and ``relwithdebinfo``
builds, so this macro will only produce output in the same builds. builds, so this macro will only produce output in the same builds.
The |ns3| model libraries do not typically use the ``NS_LOG_UNCOND(...)`` macro;
it is provided for users for assistance with debugging.
Guidelines Guidelines
========== ==========
* Start every class method with ``NS_LOG_FUNCTION(this << args...);`` * Start every significant class method with ``NS_LOG_FUNCTION(this << args...);``
This enables easy function call tracing. This enables easy function call tracing.
* Except: don't log operators or explicit copy constructors, * Exception 1: don't log operators or explicit copy constructors,
since these will cause infinite recursion and stack overflow. since these will cause infinite recursion and stack overflow.
* Exception 2: For simple methods such as getters, avoid function
logging because it tends to overload the logging output.
* For methods without arguments use the same form: * For methods without arguments use the same form:
``NS_LOG_FUNCTION(this);`` ``NS_LOG_FUNCTION(this);``
@@ -467,26 +472,49 @@ Guidelines
* Without arguments use ``NS_LOG_FUNCTION_NOARGS();`` * Without arguments use ``NS_LOG_FUNCTION_NOARGS();``
* Use ``NS_LOG_ERROR`` for serious error conditions that probably * Use ``NS_LOG_ERROR`` for serious error conditions that probably
invalidate the simulation execution. invalidate the simulation execution. Note that in |ns3|, we typically
abort the simulation under such conditions rather than log it as
an error (which might go undetected if the user is not using logging).
The ``NS_ABORT_MSG_IF/UNLESS(cond,msg)`` macros and variants, as well
as the lower-level ``NS_FATAL_ERROR(msg)`` macro, can be used to terminate
the simulation with an error message.
* Use ``NS_LOG_WARN`` for unusual conditions that may be correctable. * Use ``NS_LOG_WARN`` for unusual conditions that are not considered
invalid. An example might be that some resource has been exhausted
(e.g., the DHCP server has run out of addresses to allocate).
Please give some hints as to the nature of the problem and how Please give some hints as to the nature of the problem and how
it might be corrected. it might be corrected.
* ``NS_LOG_DEBUG`` is usually used in an *ad hoc* way to understand * Use ``NS_LOG_INFO`` for events that cause a state change in the model.
the execution of a model. Avoid using it for logging periodic events that are not causing a
state change (e.g., a Wi-Fi beacon is sent, but all nodes are already
associated to the access point). Try to be efficient in using it;
for instance, sending a message is usually an important state change event,
but try to capture this event with one single log message at the ``INFO``
level rather than multiple. If multiple log messages are desired to
fully capture the event and all of its consequences, use ``DEBUG`` level
for the additional messages. The intent of this log level is to allow a
user to examine the normal operation of a model without becoming overwhelmed
by the output.
* Use ``NS_LOG_INFO`` for additional information about the execution, * ``NS_LOG_LOGIC`` is used to trace important logic branches or decision points
such as the size of a data structure when adding/removing from it. within a function, without dumping all details of the variable states,
called function return values, individual iterations, etc. It may be useful
to think of it as a less granular level of function logging than ``DEBUG,``
and may not be used by all models (some authors may choose to only use
``DEBUG`` level for full logging).
* Use ``NS_LOG_LOGIC`` to trace important logic branches within a function. * ``NS_LOG_DEBUG`` is usually used for full voluminous debugging, and contains
much more information than ``NS_LOG_INFO``, such as the detailed execution
logic of functions and the values that variables take within those functions.
* Test that your logging changes do not break the code. * Test that your logging changes do not break the code.
Run some example programs with all log components turned on (e.g. Run some example programs with all log components turned on (e.g.
``NS_LOG="***"``). ``NS_LOG="***"``).
* Use an explicit cast for any variable of type uint8_t or int8_t, * Use a unary operator (preferred) or an explicit cast for any variable of type uint8_t or int8_t,
e.g., ``NS_LOG_LOGIC("Variable i is " << static_cast<int>(i));``. e.g., ``NS_LOG_DEBUG("Variable i is " << +i);``.
e.g., ``NS_LOG_DEBUG("Variable i is " << static_cast<int>(i));`` or
Without the cast, the integer is interpreted as a char, and the result Without the cast, the integer is interpreted as a char, and the result
will be most likely not in line with the expectations. will be most likely not in line with the expectations.
This is a well documented C++ 'feature'. This is a well documented C++ 'feature'.

20
src/core/examples/log-example.cc
View File

@@ -51,9 +51,9 @@ FreeEvent()
NS_LOG_ERROR("FreeEvent: error msg"); NS_LOG_ERROR("FreeEvent: error msg");
NS_LOG_WARN("FreeEvent: warning msg"); NS_LOG_WARN("FreeEvent: warning msg");
NS_LOG_DEBUG("FreeEvent: debug msg");
NS_LOG_INFO("FreeEvent: info msg"); NS_LOG_INFO("FreeEvent: info msg");
NS_LOG_LOGIC("FreeEvent: logic msg"); NS_LOG_LOGIC("FreeEvent: logic msg");
NS_LOG_DEBUG("FreeEvent: debug msg");
} }
/** Simple object to aggregate to a node. /** Simple object to aggregate to a node.
@@ -93,9 +93,9 @@ class MyEventObject : public Object
NS_LOG_ERROR("MyEventObject:Event: error msg"); NS_LOG_ERROR("MyEventObject:Event: error msg");
NS_LOG_WARN("MyEventObject:Event: warning msg"); NS_LOG_WARN("MyEventObject:Event: warning msg");
NS_LOG_DEBUG("MyEventObject:Event: debug msg");
NS_LOG_INFO("MyEventObject:Event: info msg"); NS_LOG_INFO("MyEventObject:Event: info msg");
NS_LOG_LOGIC("MyEventObject:Event: logic msg"); NS_LOG_LOGIC("MyEventObject:Event: logic msg");
NS_LOG_DEBUG("MyEventObject:Event: debug msg");
} }
}; // MyEventObject }; // MyEventObject
@@ -110,26 +110,26 @@ main(int argc, char** argv)
CommandLine cmd; CommandLine cmd;
cmd.Parse(argc, argv); cmd.Parse(argc, argv);
NS_LOG_UNCOND("Creating a Node"); NS_LOG_DEBUG("Creating a Node");
auto node = CreateObject<Node>(); auto node = CreateObject<Node>();
NS_LOG_UNCOND("Creating MyEventObject"); NS_LOG_DEBUG("Creating MyEventObject");
auto myObj = CreateObject<MyEventObject>(); auto myObj = CreateObject<MyEventObject>();
NS_LOG_UNCOND("Aggregating MyEventObject to Node"); NS_LOG_DEBUG("Aggregating MyEventObject to Node");
node->AggregateObject(myObj); node->AggregateObject(myObj);
NS_LOG_UNCOND("Scheduling the MyEventObject::Event with node context"); NS_LOG_INFO("Scheduling the MyEventObject::Event with node context");
Simulator::ScheduleWithContext(node->GetId(), Seconds(3), &MyEventObject::Event, &(*myObj)); Simulator::ScheduleWithContext(node->GetId(), Seconds(3), &MyEventObject::Event, &(*myObj));
NS_LOG_UNCOND("Scheduling FreeEvent"); NS_LOG_INFO("Scheduling FreeEvent");
Simulator::Schedule(Seconds(5), FreeEvent); Simulator::Schedule(Seconds(5), FreeEvent);
NS_LOG_UNCOND("Starting run..."); NS_LOG_DEBUG("Starting run...");
Simulator::Run(); Simulator::Run();
NS_LOG_UNCOND("... run complete"); NS_LOG_DEBUG("... run complete");
Simulator::Destroy(); Simulator::Destroy();
NS_LOG_UNCOND("Goodbye"); NS_LOG_DEBUG("Goodbye");
return 0; return 0;
} }

16
src/core/model/log.h
View File

@@ -100,17 +100,17 @@ enum LogLevel
LOG_WARN = 0x00000002, //!< Warning messages. LOG_WARN = 0x00000002, //!< Warning messages.
LOG_LEVEL_WARN = 0x00000003, //!< LOG_WARN and above. LOG_LEVEL_WARN = 0x00000003, //!< LOG_WARN and above.
LOG_DEBUG = 0x00000004, //!< Rare ad-hoc debug messages. LOG_INFO = 0x00000004, //!< Something happened to change state.
LOG_LEVEL_DEBUG = 0x00000007, //!< LOG_DEBUG and above. LOG_LEVEL_INFO = 0x00000007, //!< LOG_INFO and above.
LOG_INFO = 0x00000008, //!< Informational messages (e.g., banners). LOG_FUNCTION = 0x00000008, //!< Function tracing for non-trivial function calls.
LOG_LEVEL_INFO = 0x0000000f, //!< LOG_INFO and above. LOG_LEVEL_FUNCTION = 0x0000000f, //!< LOG_FUNCTION and above.
LOG_FUNCTION = 0x00000010, //!< Function tracing. LOG_LOGIC = 0x00000010, //!< Debugging logs for key branches and decisions in a function.
LOG_LEVEL_FUNCTION = 0x0000001f, //!< LOG_FUNCTION and above. LOG_LEVEL_LOGIC = 0x0000001f, //!< LOG_LOGIC and above.
LOG_LOGIC = 0x00000020, //!< Control flow tracing within functions. LOG_DEBUG = 0x00000020, //!< Full voluminous logging to support debugging.
LOG_LEVEL_LOGIC = 0x0000003f, //!< LOG_LOGIC and above. LOG_LEVEL_DEBUG = 0x0000003f, //!< LOG_DEBUG and above.
LOG_ALL = 0x0fffffff, //!< Print everything. LOG_ALL = 0x0fffffff, //!< Print everything.
LOG_LEVEL_ALL = LOG_ALL, //!< Print everything. LOG_LEVEL_ALL = LOG_ALL, //!< Print everything.