Project

General

Profile

Feature #3562

Logging facility

Added by Junxiao Shi over 4 years ago. Updated almost 4 years ago.

Status:
Closed
Priority:
Normal
Assignee:
Category:
Utils
Target version:
Start date:
Due date:
% Done:

100%

Estimated time:
9.00 h

Description

Introduce a logging facility, similar to NFD logging.

Benefits: It's easier to debug applications based on ndn-cxx and the library itself.

Caution: When logging is disabled, overhead should be low.

This issue includes the logging API and its test cases;
this issue excludes logs from various components.


Related issues

Related to NLSR - Feature #3949: Use ndn-cxx logging facilityClosedDamian Coomes02/06/201706/09/2017

Actions
Blocks ndn-cxx - Feature #3563: Face loggingClosedJunxiao Shi

Actions
Blocks ndn-cxx - Feature #3666: Logging facility: custom loggerClosedAlex Afanasyev

Actions
Blocks ndn-cxx - Feature #3667: Logging facility: synchronous sink frontendNew

Actions
Blocks ndn-cxx - Feature #3668: Logging facility: sink auto_flushClosedAlex Afanasyev

Actions
Blocks ndn-tools - Feature #3689: chunks: add flexible loggingDuplicate

Actions
#1

Updated by Junxiao Shi over 4 years ago

Some work is done during Mar 2016 hackathon, and these code can be reused.

https://github.com/2nd-ndn-hackathon/ndn-cxx-logging

#2

Updated by Junxiao Shi over 4 years ago

#3

Updated by Davide Pesavento over 4 years ago

When logging is disabled, overhead should be low.

Let me elaborate. When logging is disabled at compile time, the overhead should be zero (easy to do with macros). When logging is disabled at run time for a specific component, the overhead should be minimal (substantially harder to do, esp if logging must be thread-safe).

#4

Updated by Junxiao Shi about 4 years ago

20160621 NFD call talked about the plan on bringing this into ndn-cxx master branch.

@Davide, since you are familiar with this feature and the underlying libraries, can this be assigned to you?

#5

Updated by Davide Pesavento about 4 years ago

Junxiao Shi wrote:

@Davide, since you are familiar with this feature and the underlying libraries, can this be assigned to you?

It depends... consider that I won't have time to work on it at least until October.

#6

Updated by Junxiao Shi about 4 years ago

  • Assignee set to Junxiao Shi

Looks like I'm the most capable person after Davide.

#7

Updated by Junxiao Shi almost 4 years ago

  • Status changed from New to In Progress
  • Target version set to v0.5
#8

Updated by Junxiao Shi almost 4 years ago

  • % Done changed from 0 to 30

https://gerrit.named-data.net/2918 patchset1 is a copy from hackathon repository; patchset2 is rebased onto recent HEAD; patchset3 updates license boilerplates, which could serve as a basis for other logging-related issues.

patchset4 reverts files unrelated to #3562 (logging usage in Face, Controller, and SegmentFetcher), and attempts to add unit testing.

However, unit testing isn't working:

  • Boost.Log is asynchronous. It's necessary to flush the logger before output_test_stream can receive log lines.
  • It's necessary to save the state (log level settings, and destination) of LoggerFactory before entering certain test cases, and restore the state when leaving test cases.
  • The test cases should be able to mock NDN_CXX_LOG environ.
#9

Updated by Junxiao Shi almost 4 years ago

  • Status changed from In Progress to Code review
  • % Done changed from 30 to 100

https://gerrit.named-data.net/2918 patchset5 completes the items in note-8.

#10

Updated by Davide Pesavento almost 4 years ago

I think the logging subsystem should be made somewhat configurable. I can think of two major things right now:

  • synchronous vs asynchronous sink frontend
  • enable/disable auto_flush in the sink backend (performance vs reliability tradeoff)
#11

Updated by Junxiao Shi almost 4 years ago

I agree with note-10 but they should be in separate issues for the future.

#12

Updated by Junxiao Shi almost 4 years ago

#13

Updated by Junxiao Shi almost 4 years ago

  • Blocks Feature #3667: Logging facility: synchronous sink frontend added
#14

Updated by Junxiao Shi almost 4 years ago

#15

Updated by Junxiao Shi almost 4 years ago

do we want to always (unconditionaly) build the generic logging facility (for 3rd party apps use), but make internal ndn-cxx logging switchable at build-time (to avoid all kind of overhead)?

I think the eventually answer should be YES. But currently it's disabled altogether, because the logging facility is not yet ready for use externally.

For example:
Imagine NFD logging is replaced by logging facility, and both ndn-cxx and NFD declare a logger named Face.
It would be unclear whether the configuration "Face=DEBUG" wants to enable ndn::Face logging or nfd::Face logging.
This and other similar problems should be solved in separate issues, before the logging facility is built by default and exposed for external use.

#16

Updated by Junxiao Shi almost 4 years ago

Currently, logging macros are named NDN_CXX_LOG_*. I wonder whether CXX is necessary.

So far, #include guards start with NDN_ rather than NDN_CXX_. NDN_LOG_* would make code calling logger functions shorter.

#17

Updated by Davide Pesavento almost 4 years ago

Junxiao Shi wrote:

Currently, logging macros are named NDN_CXX_LOG_*. I wonder whether CXX is necessary.

So far, #include guards start with NDN_ rather than NDN_CXX_. NDN_LOG_* would make code calling logger functions shorter.

+1

#18

Updated by Davide Pesavento almost 4 years ago

Junxiao Shi wrote:

I think the eventually answer should be YES. But currently it's disabled altogether, because the logging facility is not yet ready for use externally.

I assumed it was public API...

Imagine NFD logging is replaced by logging facility, and both ndn-cxx and NFD declare a logger named Face.
It would be unclear whether the configuration "Face=DEBUG" wants to enable ndn::Face logging or nfd::Face logging.

I don't see the problem... NFD and ndn-cxx should use different env variables.

This and other similar problems should be solved in separate issues, before the logging facility is built by default and exposed for external use.

Fine with me but let's open a ticket, code duplication between NFD and ndn-cxx isn't a good thing.

#19

Updated by Junxiao Shi almost 4 years ago

  • Status changed from Code review to In Progress
  • % Done changed from 100 to 70

20160721 call decides:

--with-logging flag should be eliminated. Logging facility is compiled and exposed at all times.

Logging facility is enabled by application on an opt-in basis.

This is already supported through Logging::setDestination.

The overhead of logging macros should be no more than a comparison when logging is not enabled.

In 2918,15 code, default severity level is INFO, so any messages at or above this level is generated and written to a null stream, which violates this requirement.

I need to change the initial severity level to NONE, but set the default level to INFO the first time when Logging::setDestination is invoked, or severity levels are set through Logging::setLevel or environ.

Finally, some testing is needed to ensure application can still compile and operate with logging facility compiled in but not enabled.

#20

Updated by Davide Pesavento almost 4 years ago

Junxiao Shi wrote:

The overhead of logging macros should be no more than a comparison when logging is not enabled.

Fully agree.

In 2918,15 code, default severity level is INFO, so any messages at or above this level is generated and written to a null stream, which violates this requirement.

I need to change the initial severity level to NONE, but set the default level to INFO the first time when Logging::setDestination is invoked, or severity levels are set through Logging::setLevel or environ.

And then what do you do if the app calls setDestination(nullptr) after a while? Do you set the levels back to NONE? What if the level of some modules were individually changed by the app?

Finally, some testing is needed to ensure application can still compile and operate with logging facility compiled in but not enabled.

I cannot parse this sentence.

#21

Updated by Junxiao Shi almost 4 years ago

Answer to note-20:

The "NONE" optimization is applied only before the first setDestination call. If destination is set OR severity levels are set (thru function call or environ), "NONE" optimization won't be applied again.

#22

Updated by Davide Pesavento almost 4 years ago

Junxiao Shi wrote:

The "NONE" optimization is applied only before the first setDestination call. If destination is set OR severity levels are set (thru function call or environ), "NONE" optimization won't be applied again.

hmmm I don't know... I don't like it too much... it's somewhat inconsistent/asymmetric behavior. What would be the downside of simply defaulting all log modules to NONE (the additional function call for the app is not a big deal in my opinion)? Or at this point we could have a default destination of std::clog/cerr, if modules default to NONE...

#23

Updated by Junxiao Shi almost 4 years ago

I agree with note-22 to set default severity at NONE and default destination to std::clog.

#24

Updated by Junxiao Shi almost 4 years ago

  • % Done changed from 70 to 90

https://gerrit.named-data.net/2918 patchset16 fulfills note-19 and note-23 code changes.

#25

Updated by Davide Pesavento almost 4 years ago

#26

Updated by Junxiao Shi almost 4 years ago

  • Status changed from In Progress to Closed
  • % Done changed from 90 to 100
#27

Updated by Junxiao Shi almost 4 years ago

  • Status changed from Closed to Feedback

As indicated in note-16 note-17, the macros should be named NDN_LOG_*, but commit:7d05427cc10dd3529ff6f709f75055d0cd3883a7 is still using NDN_CXX_LOG_* names.

https://gerrit.named-data.net/3045 corrects the macro names.

#28

Updated by Junxiao Shi almost 4 years ago

  • Status changed from Feedback to Closed
#29

Updated by Ashlesh Gawande over 3 years ago

Also available in: Atom PDF