|
|
### WIP
|
|
|
|
|
|
https://gitlab.isc.org/isc-projects/kea/-/issues/1680
|
|
|
|
|
|
# Related support issues
|
|
|
|
|
|
### 1.
|
|
|
|
|
|
https://support.isc.org/Ticket/Display.html?id=17277
|
|
|
- print relay agent option 82
|
|
|
- custom options and order of options
|
|
|
- already opened ticket https://gitlab.isc.org/isc-projects/kea/-/issues/167
|
|
|
|
|
|
### 2.
|
|
|
|
|
|
https://support.isc.org/Ticket/Display.html?id=17559
|
|
|
- decrease file size
|
|
|
- rotate files faster than 1 day
|
|
|
- compress files
|
|
|
- possible issue: if file is deleted it is not recreated??? - maybe log if file has been deleted on disk and the server has still the FD opened
|
|
|
- interesting ticket to read: https://support.isc.org/Ticket/Display.html?id=17565
|
|
|
|
|
|
### 3.
|
|
|
|
|
|
https://support.isc.org/Ticket/Display.html?id=17523
|
|
|
- custom formatting options
|
|
|
|
|
|
### 4.
|
|
|
|
|
|
https://support.isc.org/Ticket/Display.html?id=17598
|
|
|
- print as ASCII
|
|
|
|
|
|
### Summary
|
|
|
|
|
|
All requested features:
|
|
|
|
|
|
- print relay agent option 82
|
|
|
- custom options and order of options
|
|
|
- decrease file size
|
|
|
- rotate files faster than 1 day
|
|
|
- compress files
|
|
|
- possible issue: if file is deleted it is not recreated??? - maybe log if file has been deleted on disk and the server has still the FD opened
|
|
|
- custom formatting options
|
|
|
- print as ASCII
|
|
|
|
|
|
This design document will try to provide a solution for the previously mentioned feature requests and issues.
|
|
|
|
|
|
# Custom logging
|
|
|
|
|
|
The custom logging needs to be flexible enough to give the user the possibility to choose the data and format which will be logged for lease allocation/release events.
|
|
|
For this to be possible, the isc::dhcp::evaluateString function can be used.
|
|
|
Internally it will use an isc::dhcp::EvalContext instance to parse the content of a regular expression, and to generate an isc::dhcp::Expression. The user should be able to use both the incoming packet and the outgoing packet as data source for the logged information.
|
|
|
|
|
|
```
|
|
|
class BackendStore {
|
|
|
...
|
|
|
void
|
|
|
setRequestFormatExpression(const std::string& extended_format) {
|
|
|
Option::Universe universe;
|
|
|
if (CfgMgr::instance().getFamily() == AF_INET) {
|
|
|
universe = Option::V4;
|
|
|
} else {
|
|
|
universe = Option::V6;
|
|
|
}
|
|
|
EvalContext eval_ctx(universe);
|
|
|
eval_ctx.parseString(extended_format, EvalContext::PARSER_STRING);
|
|
|
request_expression_.reset(new Expression(eval_ctx.expression));
|
|
|
}
|
|
|
|
|
|
void
|
|
|
ExpressionPtr getRequestFormatExpression() {
|
|
|
return (request_expression_);
|
|
|
}
|
|
|
|
|
|
void
|
|
|
setResponseFormatExpression(const std::string& extended_format) {
|
|
|
Option::Universe universe;
|
|
|
if (CfgMgr::instance().getFamily() == AF_INET) {
|
|
|
universe = Option::V4;
|
|
|
} else {
|
|
|
universe = Option::V6;
|
|
|
}
|
|
|
EvalContext eval_ctx(universe);
|
|
|
eval_ctx.parseString(extended_format, EvalContext::PARSER_STRING);
|
|
|
response_expression_.reset(new Expression(eval_ctx.expression));
|
|
|
}
|
|
|
|
|
|
void
|
|
|
ExpressionPtr getResponseFormatExpression() {
|
|
|
return (response_expression_);
|
|
|
}
|
|
|
|
|
|
private:
|
|
|
|
|
|
isc::dhcp::ExpressionPtr request_expression_;
|
|
|
|
|
|
isc::dhcp::ExpressionPtr response_expression_;
|
|
|
...
|
|
|
}
|
|
|
```
|
|
|
|
|
|
The hooks will be able to use the custom format only if needed (set by the user). Otherwise, the default (previous logging mode can be used). The evaluation of the custom format can affect performance, so using a default regular expression which matches the current format will not be used (even if possible).
|
|
|
|
|
|
The isc::dhcp::EvalContext will use the isc::dhcp::EvalParser to generate the isc::dhcp::Expression which will be stored and used by all custom logging functions.
|
|
|
|
|
|
As the current code uses the virtual function BackendStore::writeln to actually write data, this interface will remain unchanged. The actual data is generated by calling genLease4Entry and genLease6Entry functions, which can be modified to use the custom regular expression:
|
|
|
|
|
|
```
|
|
|
std::string genLease4Entry(const Pkt4Ptr& query,
|
|
|
const Pkt4Ptr& response,
|
|
|
const Lease4Ptr& lease,
|
|
|
const Action& action) {
|
|
|
std::string value;
|
|
|
|
|
|
auto expression = legal_store->getRequestFormatExpression();
|
|
|
if (expression && query) {
|
|
|
value = evaluateString(*expression, *query);
|
|
|
}
|
|
|
|
|
|
expression = legal_store->getResponseFormatExpression();
|
|
|
if (expression && response) {
|
|
|
value += evaluateString(*expression, *response);
|
|
|
}
|
|
|
|
|
|
if (!value.empty()) {
|
|
|
return (value);
|
|
|
}
|
|
|
...
|
|
|
}
|
|
|
|
|
|
std::string genLease6Entry(const Pkt6Ptr& query,
|
|
|
const Pkt6Ptr& response,
|
|
|
const Lease6Ptr& lease,
|
|
|
const Action& action) {
|
|
|
std::string value;
|
|
|
|
|
|
auto expression = legal_store->getRequestFormatExpression();
|
|
|
if (expression && query) {
|
|
|
value = evaluateString(*expression, *query);
|
|
|
}
|
|
|
|
|
|
expression = legal_store->getResponseFormatExpression();
|
|
|
if (expression && response) {
|
|
|
value += evaluateString(*expression, *response);
|
|
|
}
|
|
|
|
|
|
if (!value.empty()) {
|
|
|
return (value);
|
|
|
}
|
|
|
...
|
|
|
}
|
|
|
```
|
|
|
|
|
|
Accessing the hook parameters is done in the legalLog4Handler and legalLog6Handler functions.
|
|
|
These functions are responsible of setting the lease parameter and checking the subnet logging settings so that they can call the genLeaserEntry and genLease6Entry functions.
|
|
|
|
|
|
By looking at the current implementation, it seems that any action on an existing lease must be logged. For this reason there are events logged when a lease command is executed on any lease, and these events are handled by the command_processed hook.
|
|
|
Currently the only supported commands are:
|
|
|
- "lease4-add"
|
|
|
- "lease4-update"
|
|
|
- "lease4-del"
|
|
|
- "lease6-add"
|
|
|
- "lease6-update"
|
|
|
- "lease6-del"
|
|
|
|
|
|
The format for these events will remain unchanged, as the internal parser can only evaluate expressions using a packet structure, and all the available options are relative to the packet itself. The commands don't require a packet object, so the parsing is not possible.
|
|
|
|
|
|
The current implementation handles the following hook points related to packet processing:
|
|
|
- lease4_select
|
|
|
- lease4_renew
|
|
|
- lease4_decline
|
|
|
- lease4_release
|
|
|
- lease6_select
|
|
|
- lease6_renew
|
|
|
- lease6_rebind
|
|
|
- lease6_decline
|
|
|
- lease6_release
|
|
|
|
|
|
The hook points that do not require a response are:
|
|
|
- lease4_decline
|
|
|
- lease4_release
|
|
|
In conclusion, these hook points will only use the format configured for the incoming packet, and the format configured for the outgoing packet will be ignored.
|
|
|
|
|
|
All other hooks points are associated to a response packet so will use both configured formats.
|
|
|
Because these hook points are called too early in the process of packet processing, the packet might be dropped and no response sent back. To be able to maintain consistency between the logged data and the actual events processed and data send to the client, there is a need to use different hook points:
|
|
|
- pkt4_send
|
|
|
- lease4_decline
|
|
|
- lease4_release
|
|
|
- pkt6_send
|
|
|
|
|
|
Because the data in the response can differ from what the server receives in the query, the logged data will use a different parser for the request and the response, both used as the source of the evaluateString function.
|
|
|
|
|
|
By moving the hook points to pkt4_send and pkt6_send, the options on the subnet which contain logging information must be available. For this, the leases4_committed and leases6_committed functions can be used:
|
|
|
|
|
|
```
|
|
|
int leases4_committed(CalloutHandle& handle) {
|
|
|
CalloutHandle::CalloutNextStep status = handle.getStatus();
|
|
|
if (status == CalloutHandle::NEXT_STEP_DROP ||
|
|
|
status == CalloutHandle::NEXT_STEP_SKIP) {
|
|
|
return (0);
|
|
|
}
|
|
|
|
|
|
Lease4CollectionPtr leases;
|
|
|
handle.getArgument("leases4", leases);
|
|
|
handle.setContext("leases4", leases);
|
|
|
|
|
|
Lease4CollectionPtr deleted_leases;
|
|
|
handle.getArgument("deleted_leases4", deleted_leases);
|
|
|
handle.setContext("deleted_leases4", deleted_leases);
|
|
|
return (0);
|
|
|
}
|
|
|
|
|
|
int leases6_committed(CalloutHandle& handle) {
|
|
|
CalloutHandle::CalloutNextStep status = handle.getStatus();
|
|
|
if (status == CalloutHandle::NEXT_STEP_DROP ||
|
|
|
status == CalloutHandle::NEXT_STEP_SKIP) {
|
|
|
return (0);
|
|
|
}
|
|
|
|
|
|
Lease6CollectionPtr leases;
|
|
|
handle.getArgument("leases6", leases);
|
|
|
handle.setContext("leases6", leases);
|
|
|
|
|
|
Lease6CollectionPtr deleted_leases;
|
|
|
handle.getArgument("deleted_leases6", deleted_leases);
|
|
|
handle.setContext("deleted_leases6", deleted_leases);
|
|
|
return (0);
|
|
|
}
|
|
|
```
|
|
|
|
|
|
As some leases can be deleted by the server while processing and updating a lease, the deletion of leases must be logged when deleted_leases4 and deleted_leases6 containers are not empty.
|
|
|
|
|
|
As the events are only related to adding or removing a lease from the database storage, only 2 'Action' types will be used:
|
|
|
```
|
|
|
enum class Action { ASSIGN, RELEASE };
|
|
|
```
|
|
|
|
|
|
As stated before, the legalLog4Handler and legalLog6Handler need to generate the data used by genLease4Entry and genLease6Entry functions. The data contains access to the "query4", "pkt4", "lease4", "query6", "pkt6", and "lease6".
|
|
|
|
|
|
```
|
|
|
int legalLog4Handler(CalloutHandle& handle, const Action& action) {
|
|
|
if (!legal_store) {
|
|
|
LOG_ERROR(legal_log_logger,
|
|
|
LEGAL_LOG_LEASE4_NO_LEGAL_STORE);
|
|
|
return (1);
|
|
|
}
|
|
|
|
|
|
// Fetch the client's packet and the lease callout arguments.
|
|
|
Pkt4Ptr query;
|
|
|
handle.getArgument("query4", query);
|
|
|
|
|
|
Pkt4Ptr response;
|
|
|
handle.getArgument("response4", response);
|
|
|
|
|
|
Lease4Ptr lease;
|
|
|
handle.getContext("lease4", lease);
|
|
|
|
|
|
if (!lease) {
|
|
|
return (0);
|
|
|
}
|
|
|
|
|
|
ConstCfgSubnets4Ptr cfg = CfgMgr::instance().getCurrentCfg()->getCfgSubnets4();
|
|
|
try {
|
|
|
ConstSubnet4Ptr subnet = cfg->getBySubnetId(lease->subnet_id_);
|
|
|
|
|
|
if (!isLoggingDisabled(subnet)) {
|
|
|
legal_store->writeln(genLease4Entry(query, response, lease, action),
|
|
|
lease->addr_.toText());
|
|
|
}
|
|
|
|
|
|
} catch (const std::exception& ex) {
|
|
|
LOG_ERROR(legal_log_logger, LEGAL_LOG_LEASE4_WRITE_ERROR)
|
|
|
.arg(ex.what());
|
|
|
return (1);
|
|
|
}
|
|
|
|
|
|
return (0);
|
|
|
}
|
|
|
|
|
|
int legalLog6Handler(CalloutHandle& handle, const Action& action) {
|
|
|
if (!legal_store) {
|
|
|
LOG_ERROR(legal_log_logger, LEGAL_LOG_LEASE6_NO_LEGAL_STORE);
|
|
|
return (1);
|
|
|
}
|
|
|
|
|
|
// Fetch the client's packet and the lease callout arguments.
|
|
|
Pkt6Ptr query;
|
|
|
handle.getArgument("query6", query);
|
|
|
|
|
|
Pkt6Ptr response;
|
|
|
handle.getArgument("response6", response);
|
|
|
|
|
|
Lease6Ptr lease;
|
|
|
handle.getContext("lease6", lease);
|
|
|
|
|
|
if (!lease) {
|
|
|
return (0);
|
|
|
}
|
|
|
|
|
|
ConstCfgSubnets6Ptr cfg = CfgMgr::instance().getCurrentCfg()->getCfgSubnets6();
|
|
|
try {
|
|
|
ConstSubnet6Ptr subnet = cfg->getBySubnetId(lease->subnet_id_);
|
|
|
|
|
|
if (!isLoggingDisabled(subnet)) {
|
|
|
legal_store->writeln(genLease6Entry(query, response, lease, action),
|
|
|
genLease6Addr(lease));
|
|
|
}
|
|
|
|
|
|
} catch (const std::exception& ex) {
|
|
|
LOG_ERROR(legal_log_logger, LEGAL_LOG_LEASE6_WRITE_ERROR)
|
|
|
.arg(ex.what());
|
|
|
return (1);
|
|
|
}
|
|
|
|
|
|
return (0);
|
|
|
}
|
|
|
```
|
|
|
|
|
|
Having all this, all hooks must set these parameters so that they are available:
|
|
|
|
|
|
```
|
|
|
int pkt4_send(CalloutHandle& handle) {
|
|
|
CalloutHandle::CalloutNextStep status = handle.getStatus();
|
|
|
if (status == CalloutHandle::NEXT_STEP_DROP ||
|
|
|
status == CalloutHandle::NEXT_STEP_SKIP) {
|
|
|
return (0);
|
|
|
}
|
|
|
|
|
|
Lease4CollectionPtr leases;
|
|
|
handle.getContext("leases4", leases);
|
|
|
|
|
|
int current = 0;
|
|
|
int result = current;
|
|
|
|
|
|
if (leases) {
|
|
|
for (auto const& lease : *leases) {
|
|
|
handle.setContext("lease4", lease);
|
|
|
current = legalLog4Handler(handle, Action::ASSIGN);
|
|
|
if (current) {
|
|
|
result = current;
|
|
|
}
|
|
|
}
|
|
|
}
|
|
|
|
|
|
handle.getContext("deleted_leases4", leases);
|
|
|
|
|
|
if (leases) {
|
|
|
for (auto const& lease : *leases) {
|
|
|
handle.setContext("lease4", lease);
|
|
|
current = legalLog4Handler(handle, Action::RELEASE);
|
|
|
if (current) {
|
|
|
result = current;
|
|
|
}
|
|
|
}
|
|
|
}
|
|
|
|
|
|
return (result);
|
|
|
}
|
|
|
|
|
|
int lease4_release(CalloutHandle& handle) {
|
|
|
CalloutHandle::CalloutNextStep status = handle.getStatus();
|
|
|
if (status == CalloutHandle::NEXT_STEP_DROP ||
|
|
|
status == CalloutHandle::NEXT_STEP_SKIP) {
|
|
|
return (0);
|
|
|
}
|
|
|
|
|
|
Lease4Ptr lease;
|
|
|
handle.getArgument("lease4", lease);
|
|
|
handle.setContext("lease4", lease);
|
|
|
|
|
|
return (legalLog4Handler(handle, Action::RELEASE));
|
|
|
}
|
|
|
|
|
|
int lease4_decline(CalloutHandle& handle) {
|
|
|
CalloutHandle::CalloutNextStep status = handle.getStatus();
|
|
|
if (status == CalloutHandle::NEXT_STEP_DROP ||
|
|
|
status == CalloutHandle::NEXT_STEP_SKIP) {
|
|
|
return (0);
|
|
|
}
|
|
|
|
|
|
Lease4Ptr lease;
|
|
|
handle.getArgument("lease4", lease);
|
|
|
handle.setContext("lease4", lease);
|
|
|
|
|
|
return (legalLog4Handler(handle, Action::RELEASE));
|
|
|
}
|
|
|
|
|
|
int pkt6_send(CalloutHandle& handle) {
|
|
|
CalloutHandle::CalloutNextStep status = handle.getStatus();
|
|
|
if (status == CalloutHandle::NEXT_STEP_DROP ||
|
|
|
status == CalloutHandle::NEXT_STEP_SKIP) {
|
|
|
return (0);
|
|
|
}
|
|
|
|
|
|
Lease6CollectionPtr leases;
|
|
|
handle.getContext("leases6", leases);
|
|
|
|
|
|
int current = 0;
|
|
|
int result = current;
|
|
|
|
|
|
if (leases) {
|
|
|
for (auto const& lease : *leases) {
|
|
|
handle.setContext("lease6", lease);
|
|
|
current = legalLog6Handler(handle, Action::ASSIGN);
|
|
|
if (current) {
|
|
|
result = current;
|
|
|
}
|
|
|
}
|
|
|
}
|
|
|
|
|
|
handle.getContext("deleted_leases6", leases);
|
|
|
|
|
|
if (leases) {
|
|
|
for (auto const& lease : *leases) {
|
|
|
handle.setContext("lease6", lease);
|
|
|
current = legalLog6Handler(handle, Action::RELEASE);
|
|
|
if (current) {
|
|
|
result = current;
|
|
|
}
|
|
|
}
|
|
|
}
|
|
|
|
|
|
return (result);
|
|
|
}
|
|
|
|
|
|
int lease6_release(CalloutHandle& handle) {
|
|
|
CalloutHandle::CalloutNextStep status = handle.getStatus();
|
|
|
if (status == CalloutHandle::NEXT_STEP_DROP ||
|
|
|
status == CalloutHandle::NEXT_STEP_SKIP) {
|
|
|
return (0);
|
|
|
}
|
|
|
|
|
|
Lease6Ptr lease;
|
|
|
handle.getArgument("lease6", lease);
|
|
|
|
|
|
Lease6CollectionPtr deleted_leases(new Lease6Collection());
|
|
|
deleted_leases->push_back(lease);
|
|
|
handle.setContext("deleted_leases6", deleted_leases);
|
|
|
|
|
|
return (0);
|
|
|
}
|
|
|
|
|
|
int lease6_decline(CalloutHandle& handle) {
|
|
|
CalloutHandle::CalloutNextStep status = handle.getStatus();
|
|
|
if (status == CalloutHandle::NEXT_STEP_DROP ||
|
|
|
status == CalloutHandle::NEXT_STEP_SKIP) {
|
|
|
return (0);
|
|
|
}
|
|
|
|
|
|
Lease6Ptr lease;
|
|
|
handle.getArgument("lease6", lease);
|
|
|
|
|
|
Lease6CollectionPtr deleted_leases(new Lease6Collection());
|
|
|
deleted_leases->push_back(lease);
|
|
|
handle.setContext("deleted_leases6", deleted_leases);
|
|
|
|
|
|
return (0);
|
|
|
}
|
|
|
```
|
|
|
|
|
|
To note that lease4_release and lease4_decline call legalLog4Handler directly as there is no response associated to the event, so no call to pkt4_send. Because of this, the lease4_release and lease4_decline will execute the custom parser loggin on the received packet and will set "query4" argument value, but will leave the "pkt4" argument unset (only the custom parser on request will be used). In contrast, lease6_release and lease6_decline must set "deleted_leases6" in the context, so that pkt6_send which uses it must have it available.
|
|
|
|
|
|
The configuration can be done adding an extra parameter to the hook library:
|
|
|
|
|
|
```
|
|
|
"hooks-libraries": [
|
|
|
{ "library": "/usr/local/lib/libdhcp_legal_log.so",
|
|
|
"parameters": {
|
|
|
"path": "/var/lib/kea",
|
|
|
"base-name": "kea-legal",
|
|
|
"request-parser-format":
|
|
|
"if(pkt.msgtype == 5,
|
|
|
concat('Assigned address: ', concat(pkt.yiaddr, concat(' for ', concat(option[51], ' seconds')))),
|
|
|
if(pkt.msgtype == 4,
|
|
|
concat('Unassigned address: ', option[50]),
|
|
|
if(pkt.msgtype == 7,
|
|
|
concat('Released address: ', pkt.ciaddr),
|
|
|
'')))"
|
|
|
}
|
|
|
}
|
|
|
]
|
|
|
```
|
|
|
|
|
|
And the configuration function:
|
|
|
|
|
|
```
|
|
|
void parseCustomFormat(LibraryHandle& handle) {
|
|
|
ConstElementPtr param = handle.getParameter("request-parser-format");
|
|
|
if (param && param->getType() == Element::string &&
|
|
|
!param->stringValue().empty()) {
|
|
|
legal_store->setRequestFormatExpression(param->stringValue());
|
|
|
}
|
|
|
|
|
|
param = handle.getParameter("response-parser-format");
|
|
|
if (param && param->getType() == Element::string &&
|
|
|
!param->stringValue().empty()) {
|
|
|
legal_store->setResponseFormatExpression(param->stringValue());
|
|
|
}
|
|
|
}
|
|
|
```
|
|
|
|
|
|
### Things to consider:
|
|
|
It can be possible to configure custom logging for each event/hook point, but the current design only uses a uniform custom logging format.
|
|
|
|
|
|
# Rotating log |