No logs for Kea DHCP when using /var/log RAM disk

Started by Styx13, September 23, 2024, 03:43:53 AM

Previous topic - Next topic
Hello,

OPNsense 24.7.3_1

When I enable /var/log RAM disk (Use memory file system for /var/log) and reboot, I cannot see the Kea DHCP logs anymore.
I noticed the following error message in the backend log:
2024-09-22T21:40:28-04:00
Error
configd.py
[c6d73318-a7ab-448f-b5dd-926982c4c82d] Script action failed with Command '/usr/local/opnsense/scripts/syslog/queryLog.py --limit '500' --offset '0' --filter '' --module 'core' --filename 'kea' --severity 'Emergency,Alert,Critical,Error,Warning,Notice,Informational' --valid_from '1726969229.675'' returned non-zero exit status 1. at Traceback (most recent call last): File "/usr/local/opnsense/service/modules/actions/script_output.py", line 76, in execute subprocess.check_call(script_command, env=self.config_environment, shell=True, File "/usr/local/lib/python3.11/subprocess.py", line 413, in check_call raise CalledProcessError(retcode, cmd) subprocess.CalledProcessError: Command '/usr/local/opnsense/scripts/syslog/queryLog.py --limit '500' --offset '0' --filter '' --module 'core' --filename 'kea' --severity 'Emergency,Alert,Critical,Error,Warning,Notice,Informational' --valid_from '1726969229.675'' returned non-zero exit status 1.

Not sure it's related to use of ramdisk, as I also have this issue (same error message), and I'm not using ramdisk. I actually just noticed yesterday that I can't see my kea logs through the web UI, but they are present in /var/log/kea, but I hadn't had a chance to look closer yet....

September 23, 2024, 12:11:22 PM #2 Last Edit: September 23, 2024, 12:37:01 PM by dseven
This may be the actual error...

root@opnsense:~ # /usr/local/opnsense/scripts/syslog/queryLog.py --limit '20' --offset '0' --filter '' --module 'core' --filename 'kea' --severity 'Emergency,Alert,Critical,Error,Warning,Notice,Informational' --valid_from '1726930874.967'
Traceback (most recent call last):
  File "/usr/local/opnsense/scripts/syslog/queryLog.py", line 75, in <module>
    if valid_from and isoparse(record['timestamp']).timestamp() < valid_from:
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/dateutil/parser/isoparser.py", line 37, in func
    return f(self, str_in, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/dateutil/parser/isoparser.py", line 134, in isoparse
    components, pos = self._parse_isodate(dt_str)
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/dateutil/parser/isoparser.py", line 208, in _parse_isodate
    return self._parse_isodate_common(dt_str)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/dateutil/parser/isoparser.py", line 213, in _parse_isodate_common
    len_str = len(dt_str)
              ^^^^^^^^^^^
TypeError: object of type 'NoneType' has no len()
root@opnsense:~ #


I think the issue is that it doesn't handle multi-line log entries, like:

<132>1 2024-09-23T00:01:04+00:00 opnsense kea-dhcp4 63216 - [meta sequenceId="3"] WARN  [kea-dhcp4.alloc-engine.0x82d4d90d000] ALLOC_ENGINE_V4_DISCOVER_ADDRESS_CONFLICT [hwtype=1 68:39:43:d8:11:4a], cid=[01:00:00:00:00:00:00], tid=0x16e2f536: conflicting reservation for address 10.1.1.83 with existing lease Address:       10.1.1.83
Valid life:    4000
Cltt:          1727048850
Hardware addr: 68:39:43:d8:11:4a
Client id:     01:68:39:43:d8:11:4a
Subnet ID:     2
Pool ID:       0
State:         default
Relay ID:      (none)
Remote ID:     (none)

Created https://github.com/opnsense/core/issues/7888 - I'm going to try a PR with a quick fix and see what the "powers that be" think ;)