Opened 5 years ago

Closed 5 years ago

#3427 closed enhancement (fixed)

Initialize logger properly in Kea4, Kea6, D2

Reported by: tomek Owned by: tomek
Priority: medium Milestone: Kea0.9.1beta
Component: logging Version: git
Keywords: Cc:
CVSS Scoring: Parent Tickets:
Sensitive: no Defect Severity: N/A
Sub-Project: DHCP Feature Depending on Ticket:
Estimated Difficulty: 0 Add Hours to Ticket: 3
Total Hours: 47 Internal?: no

Description

Another service that was provided by BIND10 fraemwork was
logger configuration. We need to implement that.

After #3399 (Kea4), #3400 (Kea6), and #3401 (D2) are done, we'll need to implement logging configuration.

Subtickets

Change History (20)

comment:1 Changed 5 years ago by tomek

  • Owner set to tomek
  • Status changed from new to assigned

comment:2 Changed 5 years ago by tomek

  • Add Hours to Ticket changed from 0 to 32
  • Owner changed from tomek to UnAssigned
  • Status changed from assigned to reviewing
  • Total Hours changed from 0 to 32

Keep in mind that there are many things that could be improved in the logging sub-system. The goal of this ticket was to parse and apply the configuration.

This ticket introduces a Configuration structure. This is something that Marcin and I discussed some time ago. The idea is that we will have more than configuration in CfgMgr?. At the very least, there will be 2: current and new or upcoming. That will allow to rollback to previous configuration if needed. Also, over time we could develop a capability to store multiple configurations, version them and potentially operate on diffs between them. THis would allow users to provide incremental tweaks to their configurations rather than reapplying whole configuration with minimal changes. Anyway, adding this Configuration structure is just a small first step in that direction.

Proposed ChangeLog?:

8xx.	[func,doc]	tomek
	It is now possible to specify logging parameters in a
	configuration file for DHCPv4, DHCPv6 and DHCP-DDNS components.
	(Trac #3427, git abcd)

Some areas of the logging configuration are particularly tricky for unit-testing.

Please review.

comment:3 Changed 5 years ago by marcin

  • Owner changed from UnAssigned to marcin

comment:4 follow-up: Changed 5 years ago by marcin

  • Add Hours to Ticket changed from 32 to 4
  • Owner changed from marcin to tomek
  • Total Hours changed from 32 to 36

I reviewed commit 9c707375d220acff20643c41f9dad73c88fa7224

The unit test failed for me. It is most likely because of the conflicting default logger configuration and the configuration expected by the test which uses environmental variable to set the logging destination.

START TEST dhcpv4_srv.dynamic_reconfiguration
Creating Kea configuration file: /home/marcin/devel/kea/src/bin/dhcp4/tests/test_config.json.
Kea log will be stored in /home/marcin/devel/kea/src/bin/dhcp4/tests/test.log.
Running command "/home/marcin/devel/kea/src/bin/dhcp4/kea-dhcp4 -c /home/marcin/devel/kea/src/bin/dhcp4/tests/test_config.json".
INFO/test_lib: wait_for_kea .2014-07-17 10:52:23.011 INFO  [kea.dhcpsrv/8610] DHCPSRV_MEMFILE_DB opening memory file lease database: persist=false type=memfile universe=4
2014-07-17 10:52:23.011 WARN  [kea.dhcpsrv/8610] DHCPSRV_MEMFILE_NO_STORAGE running in non-persistent mode, leases will be lost after restart
2014-07-17 10:52:23.011 INFO  [kea.dhcp4/8610] DHCP4_CONFIG_NEW_SUBNET a new subnet has been added to configuration: 10.0.0.0/8 with params: t1=1000, t2=2000, valid-lifetime=4000
2014-07-17 10:52:23.011 INFO  [kea.dhcp4/8610] DHCP4_CONFIG_COMPLETE DHCPv4 server has completed configuration: 
2014-07-17 10:52:23.011 WARN  [kea.dhcp4/8610] DHCP4_NO_SOCKETS_OPEN no interface configured to listen to DHCP traffic

ERROR: server hasn't been configured.
Log file dump:
2014-07-17 10:52:23.010 INFO  [kea.dhcp4/8610] DHCP4_STARTING server starting
Shutting down Kea proccess having pid 8610.
/home/marcin/devel/kea/src/lib/testutils/dhcp_test_lib.sh: line 168:  8610 Killed                  ${bin} -c ${CFG_FILE}
FAILED dhcpv4_srv.dynamic_reconfiguration

make[3]: *** [check-local] Error 1
make[3]: Leaving directory `/home/marcin/devel/kea/src/bin/dhcp4/tests'
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `/home/marcin/devel/kea/src/bin/dhcp4/tests'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/home/marcin/devel/kea/src/bin/dhcp4'
make: *** [check] Error 2

I think you should update the src/bin/keactrl/kea.conf with the logger specification.

Question: Would there be any reason for the particular server to include multiple loggers in the configuration? I understand that there may be multiple loggers in a single configuration file which include configuration for DHCPv4 and DHCPv6 server but I don't think that the DHCPv4 server should configure the logger for DHCPv6 server and vice versa.

I have to admit I initially thought that the logger configuration for the particular process would rather be included in the part of the configuration for the particular server, so:

"Dhcp4": {

"valid-lifetime": 100,
...
"logger": {

<here is logger stuff specific to DHCPv4 server>

}

}

That way you wouldn't even need to specify the name for the logger becayse it would associated with the particular server.

Also, I wonder how the verbose mode should now work in the command line. We have the -v flag that the keactrl is using to set the debug level. I wonder what now happens if the verbose is used but the kea configuration specifies higher logging level, e.g. INFO. I think that -v should override the kea configuration setting.

doc/examples/kea4/several-subnets.json
doc/examples/kea4/single-subnet.json
doc/examples/kea6/several-subnets.json
doc/examples/kea6/simple.json
I think I don't understand the usage of the logger's name. The name in this example is "kea", so does it configure the global logger that will be used for every component using this configuration file? Or, it should have a unique name that can be associated with a particular process, e.g. DHCPv4?

And, this all brings a question if there is a way to have separate loggers for DHCPv4 and DHCPv6 components, so as I can have different destinations for them and different logging levels?

src/bin/d2/d_controller.cc
Comments for dhcp4/kea_controller.cc apply here too.

src/bin/dhcp4/kea_controller.cc
Instead of this:

logger = json->get("Logging");
if (logger) {
    // Configure logger first, so it can be applied to DHCPv6
    // configuration. If we don't have a logger, just pass
    // empty configuration.

    Daemon::configureLogger(logger, CfgMgr::instance().getConfiguration());
} else {
    // There was no Logging element defined in the config file.
    // Let's pass an empty pointer that will remove any current
    // configuration.
    Daemon::configureLogger(isc::data::ConstElementPtr(),
                            CfgMgr::instance().getConfiguration());
}

why not do this:

Daemon::configureLogger(json->get("Logging"),
                        CfgMgr::instance().getConfiguration());

It will have exactly the same effect, no?

src/bin/dhcp6/kea_controller.cc
Comments for dhcp4/kea_controller.cc apply here too.

src/lib/dhcpsrv/configuration.h

Usually #endif is followed by the CONFIGURATION_H.

src/lib/dhcpsrv/daemon.cc
src/lib/dhcpsrv/daemon.h
configureLogger: why is the log_config passed by value, and the storage passed by reference?

src/lib/dhcpsrv/logging.cc
DEFAULT_SYSLOG_NAME: It should be documented as it is not clear how this is used. Also, it should rather be in the anonymous namespace as it is not rather meant to be used from other files. If it was meant to be used from other files it would be included in the header?

LogConfigParser constructor: Should the exception thrown rather be isc::BadValue?

The following error message sounds odd:

        isc_throw(BadValue, "Unable to convert '" << severity_ptr->stringValue()
                  << "' into allowed severity (" << severity_ptr->getPosition()
                  << ")");

Wouldn't it be better to say: ''Unsupported severity value FOOBAR (kea.conf:100:1)'' ?

Similar comment for the error stating the invalid value of debug level.

applyConfiguration: The comment ''Constants: not declared static as this function...'' is wrong because the constants are actually static.

src/lib/dhcpsrv/logging.h
Do you need to include cfgmgr.h and stdint.h?

A couple of comments regarding the description of the LogConfigParser class:

  • "Interprets JSON structures and translates them to log4cplus" => "Configures log4cplus by translating Kea configuration structures"? Note, that the input to the class is not JSON, but the hierarchy of the data elements. And, assuming there may be other configuration backends that don't use JSON the description may be misleading as whether the parser can be used for other backends or not.
  • The description of the class could be extended to point out what parameters it supports.

parseConfigEntry: The documentation includes the JSON structure, I think it is fine as long as we mention that it is just an example and the format may vary.

It would be more consistent if ''defaultLogging'' had a name ''applyDefaultConfiguration'' as it serves similar purpose as ''applyConfiguration''.

It would be useful to mention why ''defaultLogging'' is static while ''applyConfiguration'' is not static.

parseConfiguration: Could log_config be passed by reference?

parseOutputOptions: it took me a while before I realized what is meant by the ''output options''. Maybe giving some examples of what they might be would work?

I think that there is no reason for protected functions be protected. They could be private because they are neither unit tested directly nor this class is a base class for any other class.

Replace:

#endif // CFGMGR_H

with:

#endif // DHCPSRV_LOGGING_H

src/lib/dhcpsrv/tests/configuration_unittest.cc
Invalid copyright date.

src/lib/dhcpsrv/tests/logging_unittest.cc
constructor: Rename nullPtr to null_ptr.

I think there should be a test that checks if multiple logger destinations can be specified.

Also, there should be a test that checks if multiple loggers can be specified.

Should the comment starting with ''There is no easy way....'' be preceded with todo?

Last edited 5 years ago by marcin (previous) (diff)

comment:5 in reply to: ↑ 4 Changed 5 years ago by tomek

  • Add Hours to Ticket changed from 4 to 8
  • Owner changed from tomek to marcin
  • Total Hours changed from 36 to 44

Replying to marcin:

I reviewed commit 9c707375d220acff20643c41f9dad73c88fa7224

The unit test failed for me. It is most likely because of the conflicting default logger configuration and the configuration expected by the test which uses environmental variable to set the logging destination.

START TEST dhcpv4_srv.dynamic_reconfiguration
...

Oops, fixed now.

I think you should update the src/bin/keactrl/kea.conf with the logger specification.

Updated.

Question: Would there be any reason for the particular server to include multiple loggers in the configuration? I understand that there may be multiple loggers in a

Yes, at least in principle. Each daemon has at least 2 loggers. For example dhcp4 has kea.dhcp4 and kea.dhcpsrv. You can increase logging of the libdhcpsrv if you want to debug it.

I have to admit I initially thought that the logger configuration for the particular process would rather be included in the part of the configuration for the particular server, so:

"Dhcp4": {

"valid-lifetime": 100,
...
"logger": {

<here is logger stuff specific to DHCPv4 server>

}

}

That way you wouldn't even need to specify the name for the logger becayse it would associated with the particular server.

I tend to agree with that suggestion. The argument for structuring it as it now was to keep whatever we had in Kea 0.8. Changing it to what you proposed is feasible and rather desired, but it would take more time than we planned for logging tweaks.

Also, I wonder how the verbose mode should now work in the command line. We have the -v flag that the keactrl is using to set the debug level. I wonder what now happens if the verbose is used but the kea configuration specifies higher logging level, e.g. INFO. I think that -v should override the kea configuration setting.

After our discussion on Jabber, I've extended the code a bit. When -v is specified, the servers become verbose, even if config file says otherwise. They just override the configuration as if it was DEBUG with debuglevel 99.

doc/examples/kea4/several-subnets.json
doc/examples/kea4/single-subnet.json
doc/examples/kea6/several-subnets.json
doc/examples/kea6/simple.json
I think I don't understand the usage of the logger's name. The name in this example is "kea", so does it configure the global logger that will be used for every component using this configuration file? Or, it should have a unique name that can be associated with a particular process, e.g. DHCPv4?

The loggers are hierarchical. This is similar to what we had in bind10. The root logger was called "bind10".

And, this all brings a question if there is a way to have separate loggers for DHCPv4 and DHCPv6 components, so as I can have different destinations for them and different logging levels?

Hmmm. Good question. I will need to make some experiments next week.

src/bin/d2/d_controller.cc
Comments for dhcp4/kea_controller.cc apply here too.

I hope I addressed them.

src/bin/dhcp4/kea_controller.cc
Instead of this:

logger = json->get("Logging");
if (logger) {
    // Configure logger first, so it can be applied to DHCPv6
    // configuration. If we don't have a logger, just pass
    // empty configuration.

    Daemon::configureLogger(logger, CfgMgr::instance().getConfiguration());
} else {
    // There was no Logging element defined in the config file.
    // Let's pass an empty pointer that will remove any current
    // configuration.
    Daemon::configureLogger(isc::data::ConstElementPtr(),
                            CfgMgr::instance().getConfiguration());
}

why not do this:

Daemon::configureLogger(json->get("Logging"),
                        CfgMgr::instance().getConfiguration());

It will have exactly the same effect, no?

Yes. Updated in d2/kea4/kea6.

src/bin/dhcp6/kea_controller.cc
Comments for dhcp4/kea_controller.cc apply here too.

Also done.

src/lib/dhcpsrv/configuration.h

Usually #endif is followed by the CONFIGURATION_H.

Added.

src/lib/dhcpsrv/daemon.cc
src/lib/dhcpsrv/daemon.h
configureLogger: why is the log_config passed by value, and the storage passed by reference?

Both are now passed by reference.

src/lib/dhcpsrv/logging.cc
DEFAULT_SYSLOG_NAME: It should be documented as it is not clear how this is used. Also, it should rather be in the anonymous namespace as it is not rather meant to be used from other files. If it was meant to be used from other files it would be included in the header?

Moved this to log/logger_name.h and wrapped with getDefaultRootLoggerName()

LogConfigParser constructor: Should the exception thrown rather be isc::BadValue?

Updated.

The following error message sounds odd:

        isc_throw(BadValue, "Unable to convert '" << severity_ptr->stringValue()
                  << "' into allowed severity (" << severity_ptr->getPosition()
                  << ")");

Wouldn't it be better to say: ''Unsupported severity value FOOBAR (kea.conf:100:1)'' ?

Changed as requested.

Similar comment for the error stating the invalid value of debug level.

Changed as well.

applyConfiguration: The comment ''Constants: not declared static as this function...'' is wrong because the constants are actually static.

Comment removed.

src/lib/dhcpsrv/logging.h
Do you need to include cfgmgr.h and stdint.h?

No, removed.

A couple of comments regarding the description of the LogConfigParser class:

  • "Interprets JSON structures and translates them to log4cplus" => "Configures log4cplus by translating Kea configuration structures"? Note, that the input to the class is not JSON, but the hierarchy of the data elements. And, assuming there may be other configuration backends that don't use JSON the description may be misleading as whether the parser can be used for other backends or not.
  • The description of the class could be extended to point out what parameters it supports.

parseConfigEntry: The documentation includes the JSON structure, I think it is fine as long as we mention that it is just an example and the format may vary.

It would be more consistent if ''defaultLogging'' had a name ''applyDefaultConfiguration'' as it serves similar purpose as ''applyConfiguration''.

Renamed.

It would be useful to mention why ''defaultLogging'' is static while ''applyConfiguration'' is not static.

I tweaked the design a bit and this was a leftover. Fixed.

parseConfiguration: Could log_config be passed by reference?

It could and it does now.

parseOutputOptions: it took me a while before I realized what is meant by the ''output options''. Maybe giving some examples of what they might be would work?

That's what they were called in the bindctl and JSON config. Using "options" in DHCP context is a bad idea.

I think that there is no reason for protected functions be protected. They could be private because they are neither unit tested directly nor this class is a base class for any other class.

They are private now.

src/lib/dhcpsrv/tests/configuration_unittest.cc
Invalid copyright date.

Fixed.

src/lib/dhcpsrv/tests/logging_unittest.cc
constructor: Rename nullPtr to null_ptr.

Renamed.

I think there should be a test that checks if multiple logger destinations can be specified.

There is one now.

Also, there should be a test that checks if multiple loggers can be specified.

There is one now.

Should the comment starting with ''There is no easy way....'' be preceded with todo?

Yes.

There's still one outstanding test failure in keactl shell tests. My understanding is that the keactl/tests/keactl_tests.sh.in should be modified (similar to recent changes in dhcp6/tests/dhcp6_process_tests.sh.in). I just ran out of time tonight.

If you could look at it - great. If not, I'll try to fix the issue next week. Reassigning to you, so you can verify the changes.

comment:6 follow-up: Changed 5 years ago by marcin

  • Add Hours to Ticket changed from 8 to 3
  • Owner changed from marcin to tomek
  • Total Hours changed from 44 to 47

Reviewed commit 8449c61018358a2cfc2478e2a747e3ed519b29b8.

You forgot to update the keactrl tests with the logger configuration and as a result I get this:

START TEST keactrl.start_all_servers_no_verbose_test
Creating Kea configuration file: /home/marcin/devel/kea/src/bin/keactrl/tests/test_config.json.
Creating keactrl configuration file: /home/marcin/devel/kea/src/bin/keactrl/tests/keactrl_test.conf.
Kea log will be stored in /home/marcin/devel/kea/src/bin/keactrl/tests/test.log.
Starting Kea: /home/marcin/devel/kea/src/bin/keactrl/keactrl start -c /home/marcin/devel/kea/src/bin/keactrl/tests/keactrl_test.conf -s all
INFO/keactrl: Starting kea-dhcp4 -c /home/marcin/devel/kea/src/bin/keactrl/tests/test_config.json
INFO/keactrl: Starting kea-dhcp6 -c /home/marcin/devel/kea/src/bin/keactrl/tests/test_config.json
2014-07-23 12:30:47.197 INFO  [kea.dhcpsrv/8202] DHCPSRV_MEMFILE_DB opening memory file lease database: persist=false type=memfile universe=4
2014-07-23 12:30:47.199 WARN  [kea.dhcpsrv/8202] DHCPSRV_MEMFILE_NO_STORAGE running in non-persistent mode, leases will be lost after restart
2014-07-23 12:30:47.199 INFO  [kea.dhcp4/8202] DHCP4_CONFIG_NEW_SUBNET a new subnet has been added to configuration: 10.0.0.0/24 with params: t1=1000, t2=2000, valid-lifetime=4000
2014-07-23 12:30:47.200 INFO  [kea.dhcp4/8202] DHCP4_CONFIG_COMPLETE DHCPv4 server has completed configuration: 
2014-07-23 12:30:47.200 WARN  [kea.dhcp4/8202] DHCP4_NO_SOCKETS_OPEN no interface configured to listen to DHCP traffic
2014-07-23 12:30:47.205 INFO  [kea.dhcpsrv/8227] DHCPSRV_MEMFILE_DB opening memory file lease database: persist=false type=memfile universe=6
2014-07-23 12:30:47.205 WARN  [kea.dhcpsrv/8227] DHCPSRV_MEMFILE_NO_STORAGE running in non-persistent mode, leases will be lost after restart
2014-07-23 12:30:47.205 INFO  [kea.dhcp6/8227] DHCP6_CONFIG_NEW_SUBNET a new subnet has been added to configuration: 2001:db8:1::/64 with params t1=1000, t2=2000, pref=3000, valid=4000
2014-07-23 12:30:47.205 INFO  [kea.dhcp6/8227] DHCP6_CONFIG_COMPLETE DHCPv6 server has completed configuration: 
2014-07-23 12:30:47.205 WARN  [kea.dhcp6/8227] DHCP6_NO_SOCKETS_OPEN no interface configured to listen to DHCP traffic
INFO/keactrl: Starting kea-dhcp-ddns -c /home/marcin/devel/kea/src/bin/keactrl/tests/test_config.json
INFO/test_lib: wait_for_message DHCP6_CONFIG_COMPLETE: .2014-07-23 12:30:47.229 INFO  [kea-dhcp-ddns.dhcpddns/8252] DCTL_CONFIG_COMPLETE server has completed configuration: 
2014-07-23 12:30:47.229 INFO  [kea-dhcp-ddns.dhcpddns/8252] DHCP_DDNS_QUEUE_MGR_RECONFIGURING application is reconfiguring the queue manager
2014-07-23 12:30:47.229 INFO  [kea-dhcp-ddns.dhcpddns/8252] DHCP_DDNS_QUEUE_MGR_STARTED application's queue manager has begun listening for requests.
....................
Assertion failure: 1 != 0, for val1=1, val2=0
Timeout waiting for kea-dhcp6 to start. Expected wait_for_message return 1, returned 0.
Log file dump:
2014-07-23 12:22:47.038 INFO  [kea.dhcp4/7621] DHCP4_STARTING server starting
2014-07-23 12:22:47.065 INFO  [kea.dhcp6/7646] DHCP6_STARTING server starting
2014-07-23 12:30:47.195 INFO  [kea.dhcp4/8202] DHCP4_STARTING server starting
2014-07-23 12:30:47.204 INFO  [kea.dhcp6/8227] DHCP6_STARTING server starting
Shutting down Kea proccess having pid 8202.
Shutting down Kea proccess having pid 8227.
Shutting down Kea proccess having pid 8252.
FAILED keactrl.start_all_servers_no_verbose_test

make[3]: *** [check-local] Error 1
make[3]: Leaving directory `/home/marcin/devel/kea/src/bin/keactrl/tests'
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `/home/marcin/devel/kea/src/bin/keactrl/tests'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/home/marcin/devel/kea/src/bin/keactrl/tests'
make: *** [check-recursive] Error 1

doc/guide/logging.xml
One of the currently defined loggers is ''kea-dhcp-ddns.dhcpddns''. Shouldn't it be ''kea.dhcp-ddns'' or ''kea.dhcpddns''?

I have to admit I never really understood the naming of loggers. And I still don't understand why I specify the new logger using the module name ''Dhcp4'', e.g. ''Dhcp4.dhcpsrv'' rather than ''kea.dhcp4.dhcpsrv''.

src/bin/keactrl/kea.conf.in
I am afraid that this will not work as expected:

      "output_options": [
          {
            "output": "@localstatedir@/log/kea.log"
          }

The reason for that is that @localstatedir@ will be expanded using the ${prefix} variable, not to the absolute path. So the kea.conf will rather contain this:

      "output_options": [
          {
            "output": "${prefix}/var/log/kea.log"
          }

and the ${prefix} is undefined in the configuration file. This approach works for keactrl.conf however, because keactrl.conf is included as a shell script and prefix is initialized there. For the kea.conf you'd need to figure out how to get the absolute path expanded from the @localstatedir@. Perhaps you need a script to replace the ${prefix} with the absolute path. Such script could be useful for other files too.

src/lib/dhcpsrv/daemon.h
Parameter verbose should be documented for the setVerbose function.

getVerbose could be declared const.

src/lib/dhcpsrv/tests/daemon_unittest.cc
noop: Not sure if the ''y'' is a best name for the Deamon instance but I see this is a general practice in this file so ok. Perhaps ''noop'' could also be replaced with something more meaningful.

comment:7 Changed 5 years ago by marcin

I am going to be on a PTO starting from Friday, July 25th thru August 8th. Since this ticket is important for the Alpha release of Kea, I suggest that someone else takes over further reviews of this ticket while I am absent. Of course, we can still try to address it today as long as I am here.

comment:8 follow-up: Changed 5 years ago by stephen

A couple of comments:

src/bin/keactrl/kea.conf.in
If this is an example configuration file, I think I would take the past of least resistance and point the logging to the syslog file.

doc/guide/logging.xml

have to admit I never really understood the naming of loggers. And I still don't understand why I specify the new logger using the module name Dhcp4, e.g. Dhcp4.dhcpsrv rather than kea.dhcp4.dhcpsrv.

The main module of the program defines a root logger. All other defined loggers append their name to that. Hence if the root logger name of the DHCP4 process is "kea-dhcp4" say, then the "dhcpsrv" logger defined in dhcpsrv library gets the name "kea-dhcp4.dhcpsrv". Assuming that the root logger name in the DHCP6 process is "kea-dhcp6", the instance of the logger in the DHCP6 process would have the name "kea-dhcp6.dhcpsrv". So (for example) you could specify the logging such that the dhcpsrv logger logs INFO messages and above for DHCP4 and DEBUG messages (and above) for DHCP6.

The logger naming reflects the hierarchical nature of the loggers: parameters set for a logger apply to all children unless explicitly overridden. As to the names in use, looking at this ticket I note that both the DHCP4 and DHCP6 root logger names appear to be "kea". This means that if you are running both V4 and V6 servers, it will not be possible to set different logging levels for each server.

src/bin/dhcp{4,6}/main.cc
I looked at these while writing the comment above.

One issue: the logging initialization is within a "try/catch" block, where a message is written out using LOG_FATAL if an exception is thrown. The problem here is that if an exception is thrown during logging initialization, you can't guarantee that LOG_FATAL will be able to output the text.

The DHCP6 code outputs a message to cerr in addition to that output by LOG_FATAL: it should be output before the LOG_FATAL one (as LOG_FATAL may well throw an exception if logging initialization has failed). The DHCP4 code does not output to cerr on error. However, thinking about it further, it may well be better to put a separate try/catch around the logging initialization and output to cerr (or syslog) on failure: if the logging initialization succeeds, you can assume that all other messages can be logged through the logging system.

comment:9 Changed 5 years ago by tomek

Nice log4cplus in Kea context is available in src/lib/log/logger_impl.h (class comment for LoggerImpl?).
This text should be probably copied to a more prominent location.

comment:10 in reply to: ↑ 6 Changed 5 years ago by tomek

Replying to marcin:

You forgot to update the keactrl tests with the logger configuration and as a result I get this:

The underlying issue was more involved. It seems that the logging parser processed only the last element of the list, so the test kept failing. I fixed that and the test is now passing.

doc/guide/logging.xml
One of the currently defined loggers is ''kea-dhcp-ddns.dhcpddns''. Shouldn't it be ''kea.dhcp-ddns'' or ''kea.dhcpddns''?

No. That's what is being used in src/bin/d2/d2_log.cc. We may rename that, but it is outside of scope for this ticket.

I have to admit I never really understood the naming of loggers. And I still don't understand why I specify the new logger using the module name ''Dhcp4'', e.g. ''Dhcp4.dhcpsrv'' rather than ''kea.dhcp4.dhcpsrv''.

It is confusing, I agree. But hopefully after the latest changes, it will be a bit clearer. Right now it is binary-name.element, e.g. kea-dhcp4.libdhcp.

src/bin/keactrl/kea.conf.in
I am afraid that this will not work as expected:

      "output_options": [
          {
            "output": "@localstatedir@/log/kea.log"
          }

The reason for that is that @localstatedir@ will be expanded using the ${prefix} variable, not to the absolute path. So the kea.conf will rather contain this:

      "output_options": [
          {
            "output": "${prefix}/var/log/kea.log"
          }

and the ${prefix} is undefined in the configuration file. This approach works for keactrl.conf however, because keactrl.conf is included as a shell script and prefix is initialized there. For the kea.conf you'd need to figure out how to get the absolute path expanded from the @localstatedir@. Perhaps you need a script to replace the ${prefix} with the absolute path. Such script could be useful for other files too.

Wrote script for that. See tools/path_replacer.sh.

src/lib/dhcpsrv/daemon.h
Parameter verbose should be documented for the setVerbose function.

It is documented now.

getVerbose could be declared const.

It is const now.

src/lib/dhcpsrv/tests/daemon_unittest.cc
noop: Not sure if the ''y'' is a best name for the Deamon instance but I see this is a general practice in this file so ok. Perhaps ''noop'' could also be replaced with something more meaningful.

Test and object names renamed.

comment:11 in reply to: ↑ 8 Changed 5 years ago by tomek

Replying to stephen:

A couple of comments:

src/bin/keactrl/kea.conf.in
If this is an example configuration file, I think I would take the past of least resistance and point the logging to the syslog file.

The goal of this ticket was to replace the capability we lost when we got rid of the python framework, not make it more convenient. But I agree. Logging configuration is flexible and powerful, but rather complicated if you want to do simple things. We'll need to revisit how we do logging.

doc/guide/logging.xml

have to admit I never really understood the naming of loggers. And I still don't understand why I specify the new logger using the module name Dhcp4, e.g. Dhcp4.dhcpsrv rather than kea.dhcp4.dhcpsrv.

The main module of the program defines a root logger. All other defined loggers append their name to that. Hence if the root logger name of the DHCP4 process is "kea-dhcp4" say, then the "dhcpsrv" logger defined in dhcpsrv library gets the name "kea-dhcp4.dhcpsrv". Assuming that the root logger name in the DHCP6 process is "kea-dhcp6", the instance of the logger in the DHCP6 process would have the name "kea-dhcp6.dhcpsrv". So (for example) you could specify the logging such that the dhcpsrv logger logs INFO messages and above for DHCP4 and DEBUG messages (and above) for DHCP6.

The logger naming reflects the hierarchical nature of the loggers: parameters set for a logger apply to all children unless explicitly overridden. As to the names in use, looking at this ticket I note that both the DHCP4 and DHCP6 root logger names appear to be "kea". This means that if you are running both V4 and V6 servers, it will not be possible to set different logging levels for each server.

Reverted that. DHCP4 and DHCP6 now use their binary names: kea-dhcp4 and kea-dhcp6. Now you are able to set different logging levels for each server. On the other hand, you now can't say log everything to a single file easily. Well, you can, but you need 3 logger configuration elements.

src/bin/dhcp{4,6}/main.cc
I looked at these while writing the comment above.

One issue: the logging initialization is within a "try/catch" block, where a message is written out using LOG_FATAL if an exception is thrown. The problem here is that if an exception is thrown during logging initialization, you can't guarantee that LOG_FATAL will be able to output the text.

The DHCP6 code outputs a message to cerr in addition to that output by LOG_FATAL: it should be output before the LOG_FATAL one (as LOG_FATAL may well throw an exception if logging initialization has failed). The DHCP4 code does not output to cerr on error. However, thinking about it further, it may well be better to put a separate try/catch around the logging initialization and output to cerr (or syslog) on failure: if the logging initialization succeeds, you can assume that all other messages can be logged through the logging system.

Updated. The code now tries to log error using LOG_ERROR(), but if that throws, it reverts to stderr.

comment:12 Changed 5 years ago by tomek

  • Owner changed from tomek to UnAssigned

Ok, the code is now ready for another review.

I checked that it passes make check and make distcheck on Ubuntu 13.10 x64.

comment:13 Changed 5 years ago by tmark

  • Owner changed from UnAssigned to tmark

comment:14 Changed 5 years ago by tmark

Unit tests and make distcheck pass under OS-X.

In dhcp6/maing.cc you have:

    } catch (const std::exception& ex) {
        LOG_FATAL(dhcp6_logger, DHCP6_SERVER_FAILED).arg(ex.what());
        cerr << "Fatal error during start up: " << ex.what() << endl;
        ret = EXIT_FAILURE;
    }

If LOG_FATAL throws you will not hit the cerr call. You should reverse
them two.

And you should add the cerr line to the dhcp4/main.cc in its final
catch block like so:

    } catch (const std::exception& ex) {
        cerr << "Fatal error during start up: " << ex.what() << endl;
        LOG_FATAL(dhcp4_logger, DHCP4_SERVER_FAILED).arg(ex.what());
        ret = EXIT_FAILURE;
    }

    return (ret);

While you're there you should add the binary name to the cerr texts.


tools/path_replacer.sh

You ought to explain the commentary when this the script is called, and it
is does not list all the tags that are involved.

You should add "Replacing " echos for prefix and syconfdir, you only have
the one for locatstatedir.

Other than that I think you're good to go.

Other than that I think you're good to go.

comment:15 Changed 5 years ago by tmark

  • Owner changed from tmark to tomek

comment:16 Changed 5 years ago by tomek

  • Resolution set to complete
  • Status changed from reviewing to closed

Thanks a lot for all your reviews, guys. Code is now merged to master.

Finally closing ticket.

comment:17 Changed 5 years ago by jreed

  • Version set to git

See src/bin/dhcp4/kea_controller.cc and src/bin/dhcp6/kea_controller.cc which both have comment:

@todo: Implement this properly (see #3427)

And src/bin/d2/d_controller.cc has comment:

// Provide an implementation until we figure out a better way to do this.

I am re-opening this ticket as it is closed but files above still mention it.

comment:18 Changed 5 years ago by marcin

  • Milestone changed from Kea0.9 to Kea-proposed
  • Resolution complete deleted
  • Status changed from closed to reopened

comment:19 Changed 5 years ago by tomek

  • Milestone changed from Kea-proposed to Kea0.9.1

comment:20 Changed 5 years ago by tomek

  • Resolution set to fixed
  • Status changed from reopened to closed

Said code and comment was cleaned up in #3591, which is now merged. Closing.

Note: See TracTickets for help on using tickets.