Kea issueshttps://gitlab.isc.org/isc-projects/kea/-/issues2023-10-06T17:12:30Zhttps://gitlab.isc.org/isc-projects/kea/-/issues/2918ISC DHCP log emulation2023-10-06T17:12:30ZPeter DaviesISC DHCP log emulation---
name: ISC DHCP log emulation
about: Kea to generate logging similar ISC DCHP.
---
**Some initial questions**
- Are you sure your feature is not already implemented in the latest Kea version?
Kea's forensic logging hooks library ...---
name: ISC DHCP log emulation
about: Kea to generate logging similar ISC DCHP.
---
**Some initial questions**
- Are you sure your feature is not already implemented in the latest Kea version?
Kea's forensic logging hooks library can be configured generate messages that look
like ISC DHCP logging but DHCPDISCOVER/DHCPOFFER and SOLICIT/ADVERTISE
packets are not logged.
**Is your feature request related to a problem? Please describe.**
As a help to folks who are planning to migrate from ISC DCHP to Kea it may be helpful if
Kea could be induced to produce logging that approximate those generated by ISC DCHP.
**Describe the solution you'd like**
There appear to be two ways forward:
1) Enhance Kea's forensic logging hooks library.
2) Generate new logging messages at severity INFO
**Additional context**
See [RT #22155](https://support.isc.org/Ticket/Display.html?id=22155)kea2.5.3Razvan BecheriuRazvan Becheriuhttps://gitlab.isc.org/isc-projects/kea/-/issues/2629legal logging hook should be able to distinguish between administrator applie...2023-07-17T13:58:21ZWlodzimierz Wencellegal logging hook should be able to distinguish between administrator applied changes and high availability hook updatesWhile one node is assigning lease to a client it logs:
`2022-11-07 07:13:22 PST Address: 192.168.50.1 has been assigned for 1 hrs 6 mins 40 secs to a device with hardware address: hwtype=1 01:03:0d:04:0b:01, client-id: 11:01:03:0d:04:0b...While one node is assigning lease to a client it logs:
`2022-11-07 07:13:22 PST Address: 192.168.50.1 has been assigned for 1 hrs 6 mins 40 secs to a device with hardware address: hwtype=1 01:03:0d:04:0b:01, client-id: 11:01:03:0d:04:0b:01`
the other node, after receiving update, is saving:
`2022-11-07 07:13:22 PST Administrator updated information on the lease of address: 192.168.50.1 to a device with hardware address: 01:03:0d:04:0b:01, client-id: 11:01:03:0d:04:0b:01 for 1 hrs 6 mins 40 secs`
which is ok from the point of view of a hook, but not exactly correct - administrator didn't lift a finger here. HA updates should be saved in a different way.kea2.3.8Razvan BecheriuRazvan Becheriuhttps://gitlab.isc.org/isc-projects/kea/-/issues/2633autoconf directive for forensic log is in wrong m4 file2023-01-12T12:32:52ZAndrei Pavelandrei@isc.orgautoconf directive for forensic log is in wrong m4 fileThese lines are in `config.m4`, but should be in `m4/forensic_log.m4`.
```
AC_CONFIG_FILES([premium/src/hooks/dhcp/forensic_log/tests/forensic_prerotate_test.sh],
[chmod +x premium/src/hooks/dhcp/forensic_log/tes...These lines are in `config.m4`, but should be in `m4/forensic_log.m4`.
```
AC_CONFIG_FILES([premium/src/hooks/dhcp/forensic_log/tests/forensic_prerotate_test.sh],
[chmod +x premium/src/hooks/dhcp/forensic_log/tests/forensic_prerotate_test.sh])
AC_CONFIG_FILES([premium/src/hooks/dhcp/forensic_log/tests/forensic_postrotate_test.sh],
[chmod +x premium/src/hooks/dhcp/forensic_log/tests/forensic_postrotate_test.sh])
```
This would allow building a premium tarball that doesn't contain forensic logging, which currently is met with:
```
configure.ac:112: error: required file 'premium/src/hooks/dhcp/forensic_log/tests/forensic_prerotate_test.sh.in' not found
configure.ac:112: error: required file 'premium/src/hooks/dhcp/forensic_log/tests/forensic_postrotate_test.sh.in' not found
```kea2.3.4Andrei Pavelandrei@isc.orgAndrei Pavelandrei@isc.orghttps://gitlab.isc.org/isc-projects/kea/-/issues/2530Improve tests for file rotation in the forensic log hook2022-09-23T13:01:36ZFrancis DupontImprove tests for file rotation in the forensic log hookAs we found some failing unit tests for the file rotation code in the forensic log hook I propose to improve these tests using the _LOG variants of gtest macros.
Side notes:
- this should be done for all tests where only the error exce...As we found some failing unit tests for the file rotation code in the forensic log hook I propose to improve these tests using the _LOG variants of gtest macros.
Side notes:
- this should be done for all tests where only the error exception type is checked vs the error message too.
- exception types are a hierarchy so one possible mistake is to check a parent of the real exception type.
- at the opposite when all messages are checked this opens an opportunity for reducing the number of exception types: no need to have different types when the fact they are different is not used...current-stable-2.4Francis DupontFrancis Duponthttps://gitlab.isc.org/isc-projects/kea/-/issues/2286AddressSanitizer reports stack-buffer-overflow in RotatingFileTest.nowString2022-05-18T19:57:13ZAndrei Pavelandrei@isc.orgAddressSanitizer reports stack-buffer-overflow in RotatingFileTest.nowStringhttps://jenkins.aws.isc.org/job/kea-dev/job/ut-asan/117/parsed_console/:
```
[2022-01-24T17:25:00.096Z] [ RUN ] RotatingFileTest.nowString
[2022-01-24T17:25:00.096Z] =================================================================
...https://jenkins.aws.isc.org/job/kea-dev/job/ut-asan/117/parsed_console/:
```
[2022-01-24T17:25:00.096Z] [ RUN ] RotatingFileTest.nowString
[2022-01-24T17:25:00.096Z] =================================================================
[2022-01-24T17:25:00.096Z] ==22451==ERROR: AddressSanitizer: stack-buffer-overflow on address 0x7ffc57122ce0 at pc 0x7f6b36b43550 bp 0x7ffc57121ba0 sp 0x7ffc57121350
[2022-01-24T17:25:00.096Z] READ of size 263 at 0x7ffc57122ce0 thread T0
[2022-01-24T17:25:00.350Z] #0 0x7f6b36b4354f (/usr/lib/x86_64-linux-gnu/libasan.so.5+0xa854f)
[2022-01-24T17:25:00.350Z] #1 0x55ce6e792754 in std::char_traits<char>::length(char const*) /usr/include/c++/8/bits/char_traits.h:322
[2022-01-24T17:25:00.350Z] #2 0x55ce6e797961 in std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::append(char const*) /usr/include/c++/8/bits/basic_string.h:1266
[2022-01-24T17:25:00.350Z] #3 0x55ce6e7971ba in std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::operator+=(char const*) /usr/include/c++/8/bits/basic_string.h:1178
[2022-01-24T17:25:00.350Z] #4 0x55ce6e8e24a7 in TestBody /tmp/workspace/kea-dev/ut-asan/premium/src/hooks/dhcp/forensic_log/tests/rotating_file_unittests.cc:147
[2022-01-24T17:25:00.350Z] #5 0x55ce6eac4c10 in void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /usr/src/googletest/googletest/src/gtest.cc:2443
[2022-01-24T17:25:00.350Z] #6 0x55ce6eab7307 in void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /usr/src/googletest/googletest/src/gtest.cc:2479
[2022-01-24T17:25:00.350Z] #7 0x55ce6ea65913 in testing::Test::Run() /usr/src/googletest/googletest/src/gtest.cc:2517
[2022-01-24T17:25:00.350Z] #8 0x55ce6ea66d46 in testing::TestInfo::Run() /usr/src/googletest/googletest/src/gtest.cc:2693
[2022-01-24T17:25:00.350Z] #9 0x55ce6ea67912 in testing::TestCase::Run() /usr/src/googletest/googletest/src/gtest.cc:2813
[2022-01-24T17:25:00.350Z] #10 0x55ce6ea82b98 in testing::internal::UnitTestImpl::RunAllTests() /usr/src/googletest/googletest/src/gtest.cc:5179
[2022-01-24T17:25:00.350Z] #11 0x55ce6eac7c02 in bool testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /usr/src/googletest/googletest/src/gtest.cc:2443
[2022-01-24T17:25:00.350Z] #12 0x55ce6eab94fd in bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /usr/src/googletest/googletest/src/gtest.cc:2479
[2022-01-24T17:25:00.350Z] #13 0x55ce6ea7f923 in testing::UnitTest::Run() /usr/src/googletest/googletest/src/gtest.cc:4788
[2022-01-24T17:25:00.350Z] #14 0x55ce6e77ffcb in RUN_ALL_TESTS() /usr/src/googletest/googletest/include/gtest/gtest.h:2341
[2022-01-24T17:25:00.350Z] #15 0x55ce6e77fe6c in main /tmp/workspace/kea-dev/ut-asan/premium/src/hooks/dhcp/forensic_log/tests/run_unittests.cc:17
[2022-01-24T17:25:00.350Z] #16 0x7f6b335d609a in __libc_start_main ../csu/libc-start.c:308
[2022-01-24T17:25:00.350Z] #17 0x55ce6e77fcc9 in _start (/tmp/workspace/kea-dev/ut-asan/premium/src/hooks/dhcp/forensic_log/tests/.libs/libdhcp_legal_log_unittests+0x18acc9)
[2022-01-24T17:25:00.350Z]
[2022-01-24T17:25:00.350Z] Address 0x7ffc57122ce0 is located in stack of thread T0 at offset 4224 in frame
[2022-01-24T17:25:00.350Z] #0 0x55ce6e8e0d43 in TestBody /tmp/workspace/kea-dev/ut-asan/premium/src/hooks/dhcp/forensic_log/tests/rotating_file_unittests.cc:124
[2022-01-24T17:25:00.350Z]
[2022-01-24T17:25:00.350Z] This frame has 62 object(s):
[2022-01-24T17:25:00.350Z] [32, 33) '<unknown>'
[2022-01-24T17:25:00.350Z] [96, 97) '<unknown>'
[2022-01-24T17:25:00.350Z] [160, 161) '<unknown>'
[2022-01-24T17:25:00.350Z] [224, 225) '<unknown>'
[2022-01-24T17:25:00.350Z] [288, 289) '<unknown>'
[2022-01-24T17:25:00.350Z] [352, 353) '<unknown>'
[2022-01-24T17:25:00.350Z] [416, 417) '<unknown>'
[2022-01-24T17:25:00.350Z] [480, 481) '<unknown>'
[2022-01-24T17:25:00.350Z] [544, 546) '<unknown>'
[2022-01-24T17:25:00.350Z] [608, 610) '<unknown>'
[2022-01-24T17:25:00.350Z] [672, 674) '<unknown>'
[2022-01-24T17:25:00.350Z] [736, 740) 'test_day'
[2022-01-24T17:25:00.350Z] [800, 808) '<unknown>'
[2022-01-24T17:25:00.350Z] [864, 872) '<unknown>'
[2022-01-24T17:25:00.350Z] [928, 936) '<unknown>'
[2022-01-24T17:25:00.350Z] [992, 1000) '<unknown>'
[2022-01-24T17:25:00.350Z] [1056, 1064) '<unknown>'
[2022-01-24T17:25:00.350Z] [1120, 1128) '<unknown>'
[2022-01-24T17:25:00.350Z] [1184, 1192) '<unknown>'
[2022-01-24T17:25:00.350Z] [1248, 1256) '<unknown>'
[2022-01-24T17:25:00.350Z] [1312, 1320) '<unknown>'
[2022-01-24T17:25:00.350Z] [1376, 1384) '<unknown>'
[2022-01-24T17:25:00.350Z] [1440, 1448) 'gtest_msg'
[2022-01-24T17:25:00.350Z] [1504, 1512) '<unknown>'
[2022-01-24T17:25:00.350Z] [1568, 1576) '<unknown>'
[2022-01-24T17:25:00.350Z] [1632, 1640) '<unknown>'
[2022-01-24T17:25:00.350Z] [1696, 1704) '<unknown>'
[2022-01-24T17:25:00.350Z] [1760, 1768) '<unknown>'
[2022-01-24T17:25:00.350Z] [1824, 1832) '<unknown>'
[2022-01-24T17:25:00.350Z] [1888, 1896) '<unknown>'
[2022-01-24T17:25:00.350Z] [1952, 1960) '<unknown>'
[2022-01-24T17:25:00.350Z] [2016, 2024) '<unknown>'
[2022-01-24T17:25:00.350Z] [2080, 2088) '<unknown>'
[2022-01-24T17:25:00.350Z] [2144, 2152) '<unknown>'
[2022-01-24T17:25:00.350Z] [2208, 2216) '<unknown>'
[2022-01-24T17:25:00.350Z] [2272, 2280) '<unknown>'
[2022-01-24T17:25:00.350Z] [2336, 2344) '<unknown>'
[2022-01-24T17:25:00.350Z] [2400, 2408) '<unknown>'
[2022-01-24T17:25:00.350Z] [2464, 2472) '<unknown>'
[2022-01-24T17:25:00.350Z] [2528, 2544) 'gtest_ar'
[2022-01-24T17:25:00.350Z] [2592, 2608) 'gtest_ar'
[2022-01-24T17:25:00.350Z] [2656, 2672) 'params'
[2022-01-24T17:25:00.350Z] [2720, 2736) '<unknown>'
[2022-01-24T17:25:00.350Z] [2784, 2800) '<unknown>'
[2022-01-24T17:25:00.350Z] [2848, 2864) '<unknown>'
[2022-01-24T17:25:00.350Z] [2912, 2928) 'gtest_ar'
[2022-01-24T17:25:00.350Z] [2976, 3032) '<unknown>'
[2022-01-24T17:25:00.350Z] [3072, 3104) '<unknown>'
[2022-01-24T17:25:00.350Z] [3136, 3168) '<unknown>'
[2022-01-24T17:25:00.350Z] [3200, 3232) '<unknown>'
[2022-01-24T17:25:00.350Z] [3264, 3296) 'expected_string'
[2022-01-24T17:25:00.350Z] [3328, 3360) '<unknown>'
[2022-01-24T17:25:00.350Z] [3392, 3424) '<unknown>'
[2022-01-24T17:25:00.350Z] [3456, 3488) 'now_string'
[2022-01-24T17:25:00.350Z] [3520, 3552) '<unknown>'
[2022-01-24T17:25:00.350Z] [3584, 3616) '<unknown>'
[2022-01-24T17:25:00.350Z] [3648, 3680) '<unknown>'
[2022-01-24T17:25:00.350Z] [3712, 3744) 'format'
[2022-01-24T17:25:00.350Z] [3776, 3808) '<unknown>'
[2022-01-24T17:25:00.350Z] [3840, 3872) '<unknown>'
[2022-01-24T17:25:00.350Z] [3904, 3936) '<unknown>'
[2022-01-24T17:25:00.350Z] [3968, 4224) 'buf' <== Memory access at offset 4224 overflows this variable
[2022-01-24T17:25:00.350Z] HINT: this may be a false positive if your program uses some custom stack unwind mechanism or swapcontext
[2022-01-24T17:25:00.350Z] (longjmp and C++ exceptions *are* supported)
[2022-01-24T17:25:00.350Z] SUMMARY: AddressSanitizer: stack-buffer-overflow (/usr/lib/x86_64-linux-gnu/libasan.so.5+0xa854f)
[2022-01-24T17:25:00.350Z] Shadow bytes around the buggy address:
[2022-01-24T17:25:00.350Z] 0x10000ae1c540: f2 f2 f2 f2 f8 f8 f8 f8 f2 f2 f2 f2 f8 f8 f8 f8
[2022-01-24T17:25:00.350Z] 0x10000ae1c550: f2 f2 f2 f2 f8 f8 f8 f8 f2 f2 f2 f2 00 00 00 00
[2022-01-24T17:25:00.350Z] 0x10000ae1c560: f2 f2 f2 f2 00 00 00 00 f2 f2 f2 f2 00 00 00 00
[2022-01-24T17:25:00.350Z] 0x10000ae1c570: f2 f2 f2 f2 00 00 00 00 f2 f2 f2 f2 00 00 00 00
[2022-01-24T17:25:00.350Z] 0x10000ae1c580: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[2022-01-24T17:25:00.350Z] =>0x10000ae1c590: 00 00 00 00 00 00 00 00 00 00 00 00[f3]f3 f3 f3
[2022-01-24T17:25:00.350Z] 0x10000ae1c5a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[2022-01-24T17:25:00.350Z] 0x10000ae1c5b0: f1 f1 f1 f1 00 00 f2 f2 00 00 00 00 00 00 00 00
[2022-01-24T17:25:00.350Z] 0x10000ae1c5c0: 00 00 00 00 00 00 00 00 00 00 f1 f1 f1 f1 00 00
[2022-01-24T17:25:00.350Z] 0x10000ae1c5d0: f2 f2 f2 f2 f2 f2 00 00 00 00 f2 f2 f2 f2 00 00
[2022-01-24T17:25:00.350Z] 0x10000ae1c5e0: 00 00 f3 f3 f3 f3 00 00 00 00 00 00 00 00 00 00
[2022-01-24T17:25:00.350Z] Shadow byte legend (one shadow byte represents 8 application bytes):
[2022-01-24T17:25:00.350Z] Addressable: 00
[2022-01-24T17:25:00.350Z] Partially addressable: 01 02 03 04 05 06 07
[2022-01-24T17:25:00.350Z] Heap left redzone: fa
[2022-01-24T17:25:00.350Z] Freed heap region: fd
[2022-01-24T17:25:00.350Z] Stack left redzone: f1
[2022-01-24T17:25:00.350Z] Stack mid redzone: f2
[2022-01-24T17:25:00.350Z] Stack right redzone: f3
[2022-01-24T17:25:00.350Z] Stack after return: f5
[2022-01-24T17:25:00.350Z] Stack use after scope: f8
[2022-01-24T17:25:00.350Z] Global redzone: f9
[2022-01-24T17:25:00.350Z] Global init order: f6
[2022-01-24T17:25:00.350Z] Poisoned by user: f7
[2022-01-24T17:25:00.350Z] Container overflow: fc
[2022-01-24T17:25:00.350Z] Array cookie: ac
[2022-01-24T17:25:00.350Z] Intra object redzone: bb
[2022-01-24T17:25:00.350Z] ASan internal: fe
[2022-01-24T17:25:00.350Z] Left alloca redzone: ca
[2022-01-24T17:25:00.350Z] Right alloca redzone: cb
[2022-01-24T17:25:00.350Z] ==22451==ABORTING
[2022-01-24T17:25:00.350Z] FAIL: libdhcp_legal_log_unittests
[2022-01-24T17:25:00.350Z] ======================================
[2022-01-24T17:25:00.350Z] 1 of 1 test failed
[2022-01-24T17:25:00.350Z] Please report to kea-dev@lists.isc.org
[2022-01-24T17:25:00.350Z] ======================================
```
It refers to this code:
```
char buf[256];
memset(buf, '-', sizeof(buf));
std::string format("%Y%m%d");
format += buf;
```
It seems like `buf` should be null-terminated.kea2.1.6Razvan BecheriuRazvan Becheriuhttps://gitlab.isc.org/isc-projects/kea/-/issues/2181[ISC-support #19697] forensic_log hook double logs DHCPv6 packets with multip...2022-05-18T15:51:40ZDan Theisen[ISC-support #19697] forensic_log hook double logs DHCPv6 packets with multiple leases (custom log format)When using a custom log format with the forensic_log/legal_log premium hook, DHCPv6 packets that have multiple leases (for ex, an IA_NA and IA_PD lease) end up getting double (quadruple?) logged. This issue is not present when not specif...When using a custom log format with the forensic_log/legal_log premium hook, DHCPv6 packets that have multiple leases (for ex, an IA_NA and IA_PD lease) end up getting double (quadruple?) logged. This issue is not present when not specifying a custom logging format. Logs of the issue follow.
Log entries when no custom log format is present:
```
2021-11-09 02:55:07 PST Address: 2001:db8:ffff:100::1 has been assigned for 1 hrs 6 mins 40 secs to a device with DUID: 00:04:ac:fa:ac:6d:4b:0f:4c:38:9e:40:92:45:34:ad:4f:55
2021-11-09 02:55:07 PST Prefix: 2001:db8:abcd:1::/64 has been assigned for 1 hrs 6 mins 40 secs to a device with DUID: 00:04:ac:fa:ac:6d:4b:0f:4c:38:9e:40:92:45:34:ad:4f:55
```
Log entries when custom log format from kea-docs is present:
```
2021-11-09 03:04:21 PST Address: 2001:db8:ffff:100::1 has been assigned for 4000 seconds to a device with DUID: 00:04:ac:fa:ac:6d:4b:0f:4c:38:9e:40:92:45:34:ad:4f:55Prefix: 2001:db8:abcd:1::/64 has been assigned for 4000 seconds to a device with DUID: 00:04:ac:fa:ac:6d:4b:0f:4c:38:9e:40:92:45:34:ad:4f:55
2021-11-09 03:04:21 PST Address: 2001:db8:ffff:100::1 has been assigned for 4000 seconds to a device with DUID: 00:04:ac:fa:ac:6d:4b:0f:4c:38:9e:40:92:45:34:ad:4f:55Prefix: 2001:db8:abcd:1::/64 has been assigned for 4000 seconds to a device with DUID: 00:04:ac:fa:ac:6d:4b:0f:4c:38:9e:40:92:45:34:ad:4f:55
```
I've attached a kea-dhcp6 configuration file that reproduces this issuse. [Support19697-config.json](/uploads/db893b42171d2b78632d06ee8555ad40/Support19697-config.json)
This issue originates from a customer bug report that can be found here: https://support.isc.org/Ticket/Display.html?id=19697
After some quick debugging, I can see that the incorrectly formatted string is being returned from `evaluateString()` here: https://gitlab.isc.org/isc-private/kea-premium/-/blob/master/src/hooks/dhcp/forensic_log/lease6_callouts.cc#L130
You can see that the `genLease6Entry()` function has different code paths when using the default logging format vs the custom logging format. With the default logging format, only the first lease passed is worked on. When a custom format string is used, the whole packet as well as the the format string is passed to `evaluateString()`, which looks like it will try to parse out the contents of entire packet, which causes the log lines to each contain both leases: https://gitlab.isc.org/isc-projects/kea/-/blob/master/src/lib/eval/evaluate.cc#L30
The reason why the double logged entry appears twice is because `pkt6_send()` (https://gitlab.isc.org/isc-private/kea-premium/-/blob/master/src/hooks/dhcp/forensic_log/lease6_callouts.cc#L365) is calling `legalLog6Handler()` once per lease in the packet. If more than two leases are included in a packet, say multiple IA_NA leases for multiple interfaces on a requesting box, the number of logged lines will match the number of leases in the packet, and the contents of each log line will show every lease.
I'm not quite sure how to fix this short of writing a new `evaluateString()` function that works on leases instead of packets.kea2.1.4Razvan BecheriuRazvan Becheriuhttps://gitlab.isc.org/isc-projects/kea/-/issues/2208Make forensic log timestamp configurable2022-01-21T16:55:00ZPeter DaviesMake forensic log timestamp configurableThis is a tracking ticket to ensure we don't forget merge requests originating from the 19485-kea-premium tracking branch.
[RT 19485](https://support.isc.org/Ticket/Display.html?id=19485)This is a tracking ticket to ensure we don't forget merge requests originating from the 19485-kea-premium tracking branch.
[RT 19485](https://support.isc.org/Ticket/Display.html?id=19485)kea2.1.2Razvan BecheriuRazvan Becheriuhttps://gitlab.isc.org/isc-projects/kea/-/issues/2134Document custom logging format better2021-11-18T14:20:45ZTomek MrugalskiDocument custom logging format betterKea uses log4cplus library for logging. There are multiple formatting options available, but they're not well documented.
We should:
1. fix the link in the ARM Section 19.1.2
2. document available formatting options in Kea directly, rat...Kea uses log4cplus library for logging. There are multiple formatting options available, but they're not well documented.
We should:
1. fix the link in the ARM Section 19.1.2
2. document available formatting options in Kea directly, rather than provide link to external docs (that we know broke down in the past)
In particular, we should document `%Q`, which is microsecond (log4cplus calls it fractional milliseconds) timestamp.
The data is available in log4cplus sources: https://github.com/log4cplus/log4cplus/blob/master/include/log4cplus/layout.h#L293kea2.1.1Dan TheisenDan Theisenhttps://gitlab.isc.org/isc-projects/kea/-/issues/1864forensic logging documentation is duplicated2021-05-27T05:21:25ZAndrei Pavelandrei@isc.orgforensic logging documentation is duplicatedForensic logging documentation, particularly referring to custom formatting and rotation, is in two places:
* doc/sphinx/arm/hooks.rst
* premium/src/hooks/dhcp/forensic_log/libdhcp_legal_log.dox
As one gets updated, the other one gets o...Forensic logging documentation, particularly referring to custom formatting and rotation, is in two places:
* doc/sphinx/arm/hooks.rst
* premium/src/hooks/dhcp/forensic_log/libdhcp_legal_log.dox
As one gets updated, the other one gets outdated.
Revert dox file to the previous state. And complete rst with the extra information that was only placed in dox.kea1.9.9Andrei Pavelandrei@isc.orgAndrei Pavelandrei@isc.orghttps://gitlab.isc.org/isc-projects/kea/-/issues/1680[ISC-support #17598] Forensic logging enhancements2021-05-24T16:37:21ZPeter Davies[ISC-support #17598] Forensic logging enhancements**Advanced logging facility for forensic logging.**
A number of customers have been asking for enhanced logging features to be available to the forensic logging library hook.
These enhancement could include:
**Logging format:**
...**Advanced logging facility for forensic logging.**
A number of customers have been asking for enhanced logging features to be available to the forensic logging library hook.
These enhancement could include:
**Logging format:**
The ability to configure the output logging string.
Represent the client-id as ascii instead of hex.
**Logfile attributes**:
The ability to configure rollover settings
The ability automatically compresses rollover files.
[RT #17277](https://support.isc.org/Ticket/Display.html?id=17277)
[RT #17559](https://support.isc.org/Ticket/Display.html?id=17559)
[RT #17523](https://support.isc.org/Ticket/Display.html?id=17523)
[RT #17598](https://support.isc.org/Ticket/Display.html?id=17598)kea1.9.8Razvan BecheriuRazvan Becheriuhttps://gitlab.isc.org/isc-projects/kea/-/issues/1879forensic logging freebsd unit test failures2021-05-20T18:41:53ZAndrei Pavelandrei@isc.orgforensic logging freebsd unit test failureshttps://jenkins.aws.isc.org/job/kea-dev/job/ut-basic/318/
```
Test Result (3 failures / -1)
run tests / freebsd-12.1-amd64 / freebsd-12.1-amd64 results / RotatingFileTest.prerotateActions
run tests / freebsd-12.1-amd64 / freebs...https://jenkins.aws.isc.org/job/kea-dev/job/ut-basic/318/
```
Test Result (3 failures / -1)
run tests / freebsd-12.1-amd64 / freebsd-12.1-amd64 results / RotatingFileTest.prerotateActions
run tests / freebsd-12.1-amd64 / freebsd-12.1-amd64 results / RotatingFileTest.postrotateActions
run tests / freebsd-12.1-amd64 / freebsd-12.1-amd64 results / RotatingFileTest.prerotateAndPostrotateActions
```
```
rotating_file_unittests.cc:1124
Value of: fileExists(exp_name)
Actual: false
Expected: true
```kea1.9.8Andrei Pavelandrei@isc.orgAndrei Pavelandrei@isc.orghttps://gitlab.isc.org/isc-projects/kea/-/issues/1866segfault on parameter-less forensic logging2021-05-19T14:26:22ZAndrei Pavelandrei@isc.orgsegfault on parameter-less forensic loggingWhen configuring kea-dhcp[46] with a forensic logging without a "parameters" field, it segfaults.
```json
"hooks-libraries": [
{
"library": "libdhcp_legal_log.so"
}
]
```
`
kea-dhcp6: /usr/include/boost/smar...When configuring kea-dhcp[46] with a forensic logging without a "parameters" field, it segfaults.
```json
"hooks-libraries": [
{
"library": "libdhcp_legal_log.so"
}
]
```
`
kea-dhcp6: /usr/include/boost/smart_ptr/shared_ptr.hpp:728: typename boost::detail::sp_member_access<T>::type boost::shared_ptr<T>::operator->() const [with T = isc::legal_log::BackendStore; typename boost::detail::sp_member_access<T>::type = isc::legal_log::BackendStore*]: Assertion 'px != 0' failed.
`
`
#4 0x00007ffff34e1cf5 in boost::shared_ptr<isc::legal_log::BackendStore>::operator-> (this=0x7ffff3558250 <isc::legal_log::BackendStore::instance()::backend_store>) at /usr/include/boo
st/smart_ptr/shared_ptr.hpp:728
#5 0x00007ffff34decf1 in load (handle=...) at load_unload.cc:52
`
This used to work in 1.9.7.
This is also why system tests are failing on Jenkins.
`parameters` is checked on the first line of `BackendStore::parseFile()`, it returns on null, and the backend store is not instantiated further down below.
```cpp
void
BackendStore::parseFile(const ConstElementPtr& parameters) {
if (!parameters) {
return;
}
[..]
BackendStore::instance().reset(new RotatingFile(path, base, unit, count,
prerotate, postrotate));
}
```kea1.9.8Andrei Pavelandrei@isc.orgAndrei Pavelandrei@isc.orghttps://gitlab.isc.org/isc-projects/kea/-/issues/1863plus operator not working in custom forensic logging format2021-05-17T10:56:39ZAndrei Pavelandrei@isc.orgplus operator not working in custom forensic logging formatI've tried configuring kea-dhcp4 and kea-dhcp6 with custom formats with pluses. I get the following error:
```
ERROR LEGAL_LOG_LOAD_ERROR LEGAL LOGGING DISABLED! An error occurred loading the library: <string>: Invalid character: +
ERRO...I've tried configuring kea-dhcp4 and kea-dhcp6 with custom formats with pluses. I get the following error:
```
ERROR LEGAL_LOG_LOAD_ERROR LEGAL LOGGING DISABLED! An error occurred loading the library: <string>: Invalid character: +
ERROR HOOKS_LOAD_ERROR 'load' function in hook library /opt/kea/lib/kea/hooks/libdhcp_legal_log.so returned error 1
```
```
"request-parser-format": "'kea ' + 'is awesome'"
```kea1.9.8Andrei Pavelandrei@isc.orgAndrei Pavelandrei@isc.orghttps://gitlab.isc.org/isc-projects/kea/-/issues/1621implement connection recovery for forensic logging lib2021-04-01T14:48:18ZRazvan Becheriuimplement connection recovery for forensic logging lib#1375 did not implement db connection reconnect logic for forensic logging library#1375 did not implement db connection reconnect logic for forensic logging librarykea1.9.6Razvan BecheriuRazvan Becheriuhttps://gitlab.isc.org/isc-projects/kea/-/issues/1711crash on high request rate2021-02-22T11:32:06ZAndrei Pavelandrei@isc.orgcrash on high request rateUsing forensic logging with a MySQL backend yields a segmentation fault if I send approximately 1000 requests per second with perfdhcp.
perfdhcp command:
```
perfdhcp -6 -l vethclient -R 4294967295 -r 1000 -t 1
```
This is the Kea Conf...Using forensic logging with a MySQL backend yields a segmentation fault if I send approximately 1000 requests per second with perfdhcp.
perfdhcp command:
```
perfdhcp -6 -l vethclient -R 4294967295 -r 1000 -t 1
```
This is the Kea Config I used:
<details>
<summary>kea-dhcp6.conf</summary>
<code>
{
"Dhcp6": {
"config-control": {
"config-databases": [
{
"host": "127.0.0.1",
"max-reconnect-tries": 3,
"name": "keatest",
"password": "keatest",
"port": 3306,
"reconnect-wait-time": 3000,
"type": "mysql",
"user": "keatest"
}
],
"config-fetch-wait-time": 20
},
"control-socket": {
"socket-name": "/tmp/kea-dhcp6-ctrl.sock",
"socket-type": "unix"
},
"hooks-libraries": [
{
"library": "/opt/kea/lib/kea/hooks/libdhcp_legal_log.so",
"parameters": {
"base-name": "kea-forensic6",
"type": "mysql",
"name": "keatest",
"username": "keatest",
"password": "keatest"
}
},
{
"library": "/opt/kea/lib/kea/hooks/libdhcp_cb_cmds.so"
},
{
"library": "/opt/kea/lib/kea/hooks/libdhcp_lease_cmds.so"
},
{
"library": "/opt/kea/lib/kea/hooks/libdhcp_mysql_cb.so"
},
{
"library": "/opt/kea/lib/kea/hooks/libdhcp_stat_cmds.so"
}
],
"interfaces-config": {
"interfaces": [
"vethserver"
]
},
"lease-database": {
"name": "/tmp/kea-dhcp6.csv",
"persist": false,
"type": "memfile"
},
"loggers": [
{
"debuglevel": 99,
"name": "kea-dhcp6",
"output_options": [
{
"output": "stdout"
}
],
"severity": "DEBUG"
}
],
"multi-threading": {
"enable-multi-threading": true,
"thread-pool-size": 16,
"packet-queue-size": 0
},
"server-tag": "my-server",
"subnet6": [
{
"pd-pools": [
{
"delegated-len": 120,
"prefix": "2001:db8:1:0:2::",
"prefix-len": 80
}
],
"pools": [
{
"pool": "2001:db8:1:0:1::/80"
}
],
"subnet": "2001:db8:1::/64"
}
]
}
}
</code>
</details>
If I take out the `libdhcp_legal_log` hook library, the problem doesn't reproduce any more even.
The segmentation fault happened often in `StatsMgr::add()` or `IOAddress::toBytes()` but they probably have nothing to do with the actual memory corruption.
The 1000 requests per second is detrimental to reproducing this crash. Send too few and the race that probably causes this won't happen. If I send 100.000 it seems to happen less, but still happens. :shrug: This is supersistion, but I guess 1000 is close enough to Kea's limit on my machine, I get around 1% drops.
premium fix in:
https://gitlab.isc.org/isc-private/kea-premium/-/merge_requests/160
this MR needs to be backported to 1.8.xkea1.9.5Razvan BecheriuRazvan Becheriuhttps://gitlab.isc.org/isc-projects/kea/-/issues/949Add the capability to convert HEX to ASCII to the forensic logging hook and o...2021-02-16T13:50:29ZCathy AlmondAdd the capability to convert HEX to ASCII to the forensic logging hook and other formatting control---
name: Add the capability to convert HEX to ASCII to the forensic logging hook as well as other formatting control
about: Suggest an idea for this project
---
As noted in [Support ticket #15209](https://support.isc.org/Ticket/Displa...---
name: Add the capability to convert HEX to ASCII to the forensic logging hook as well as other formatting control
about: Suggest an idea for this project
---
As noted in [Support ticket #15209](https://support.isc.org/Ticket/Display.html?id=15209), it would be very useful and helpful to be able to convert HEX to ASCII when logging. For example, what is being output now is:
Address: 192.168.2.10 has been renewed for 0 hrs 10 mins 0 secs to a device with hardware address: hwtype=1 f4:f2:6d:79:cb:81, client-id: 01:f4:f2:6d:79:cb:81 connected via relay at address: 192.168.3.1, identified by circuit-id: 45:53:43:44:20:65:74:68:20:31:37:2f:33:2f:32:38:2f:31:2f:31
Being able to dissect and reformat the HEX of the circuit-id would be especially helpful.
We understand that similar code already exists for reformatting HEX to ASCII in the RADIUS and flex-id hooks, hence Engineering suggested that we open this feature request.
If you'd like more examples of 'it would be really good if it looked like ....' just ask!kea1.7.7Francis DupontFrancis Duponthttps://gitlab.isc.org/isc-projects/kea/-/issues/1445Forensic logging should cover DECLINE and RELEASE2020-10-22T17:18:24ZTomek MrugalskiForensic logging should cover DECLINE and RELEASEIt was reported (see [support#17179](https://support.isc.org/Ticket/Display.html?id=17179)) that the forensic logging could handle the situation better when:
* client sends DECLINE
* client sends RELEASE
See patch attached in the suppo...It was reported (see [support#17179](https://support.isc.org/Ticket/Display.html?id=17179)) that the forensic logging could handle the situation better when:
* client sends DECLINE
* client sends RELEASE
See patch attached in the support ticket.kea1.9.1Tomek MrugalskiTomek Mrugalskihttps://gitlab.isc.org/isc-projects/kea/-/issues/1203make the forensic/legal logging hook compatible with multi-threading2020-06-14T16:19:30ZFrancis Dupontmake the forensic/legal logging hook compatible with multi-threadingTechnically this means to add a connection pool for MySQL and PostgreSQL backends.Technically this means to add a connection pool for MySQL and PostgreSQL backends.kea1.7.9Francis DupontFrancis Dupont