[kea-dev] Suggestions for DHCP packets logs

[Chaigneau, Nicolas]

Hello,


The following are recommendations for implementing the logging of DHCP packets.

These originate from functional requirements, and from performance tests I've run (on our implementation of packets logging, handled through a hook).

Discussion is welcome as always!



1) don't use log4cplus

There is a very significant performance penalty when logging a large volume of data through log4cplus.

Packets should not be logged through log4cplus.
Packets should be written directly through a fstream. (I've measured about 30% improvement in DORA/s capacity, as compared to using log4cplus).



2) enabling packets logs

A parameter should allow to enable or disable the packets logs.



3) flushing of packets logs

There is also a performance benefit in allowing to disable explicit flushing (ie each time a line is logged) of the log file. 
In this case, automatic flushing is handled by the system and happens whenever the output buffer is full (or when the file is closed).

This is not necessarily desirable for everyone.
A parameter should be provided to control whether packets logs are flushed explicitly or automatically.



4) handle packets logs rotation

Rotation of the packets logs should not be delegated to an external task such as logrotate.
This should be handled directly by Kea.

The performance test results are unequivocal, even though this was not really expected (as logrotate is run by another CPU).

When logrotate works in copytruncate mode on the packets logs, the following happens while the log is being processed:
- Kea CPU usage spikes to 100%
- DHCP packets are being dropped (from the client point of view)

As a consequence, users cannot get leases when logrotate is processing the packets logs (and this takes some time because the files are huge - about 30 to 40 seconds for a 4.5 GB file).
This is clearly not acceptable.

A solution is to have Kea directly handle the file rotation.
This can be done on several criteria, for instance:
- on a time frame basis (eg. hourly packets log files),
- when file size exceeds a given limit,
- or a number of logged packets, ...

I've chosen the first approach, which is to log to a timestamped hourly file such as "log-packets-<YYYYMMDD><HH>".
Kea closes the file and opens a new one whenever the file name (according to current time) changes.

The rotation criteria and file name format should be configurable.
I need to rotate files hourly (otherwise the files are way too big and are very hard to handle subsequently), but some people could prefer to do so daily or not at all depending on the traffic they're dealing with.




Regards,
Nicolas.


This message contains information that may be privileged or confidential and is the property of the Capgemini Group. It is intended only for the person to whom it is addressed. If you are not the intended recipient, you are not authorized to read, print, retain, copy, disseminate, distribute, or use this message or any part thereof. If you receive this message in error, please notify the sender immediately and delete all copies of this message.