search

FRRouting / frr

The FRRouting Protocol Suite
https://frrouting.org/
Other
3.28k stars 1.24k forks source link

"Extended Logging Target" broken/not working #15281

Open corubba opened 7 months ago

corubba commented 7 months ago

Describe the bug

PR #8458 added the "Extended Logging Target", which can be used for logging to syslog and/or journald among other things. As the doc for the log syslog option states the "Extended Logging Target" is the recommended way for logging to syslog. I was however unable to get it to work on a fresh Debian 12 installation, neither with the packages provided in the FRR Debian repo nor with self-built ones. The only configuration I changed after installing the package is frr.conf to the following:

no log stdout
no log syslog

log extended mytarget
  destination journald

Starting FRR using the systemd service unit results in the following log output in journald. Note the Unknown command lines.

Feb 02 00:39:03 anycast systemd[1]: Starting frr.service - FRRouting...
Feb 02 00:39:03 anycast frrinit.sh[34984]: Starting watchfrr with command: '  /usr/lib/frr/watchfrr  -d  -F traditional   zebra mgmtd staticd'.
Feb 02 00:39:04 anycast watchfrr[34993]: [T83RR-8SM5G] watchfrr 9.2-dev starting: vty@0
Feb 02 00:39:04 anycast watchfrr[34993]: [ZCJ3S-SPH5S] zebra state -> down : initial connection attempt failed
Feb 02 00:39:04 anycast watchfrr[34993]: [ZCJ3S-SPH5S] mgmtd state -> down : initial connection attempt failed
Feb 02 00:39:04 anycast watchfrr[34993]: [ZCJ3S-SPH5S] staticd state -> down : initial connection attempt failed
Feb 02 00:39:04 anycast watchfrr[34993]: [YFT0P-5Q5YX] Forked background command [pid 34994]: /usr/lib/frr/watchfrr.sh restart all
Feb 02 00:39:04 anycast frrinit.sh[35004]: 2024/02/02 00:39:04 ZEBRA: [NNACN-54BDA][EC 4043309110] Disabling MPLS support (no kernel support)
Feb 02 00:39:04 anycast frrinit.sh[35027]: [35027|mgmtd] sending configuration
Feb 02 00:39:04 anycast frrinit.sh[35028]: [35028|zebra] sending configuration
Feb 02 00:39:04 anycast frrinit.sh[35027]: line 4: % Unknown command[4]: log extended mytarget
Feb 02 00:39:04 anycast frrinit.sh[35027]: line 5: % Unknown command[4]:   destination journald
Feb 02 00:39:04 anycast frrinit.sh[35027]: [35027|mgmtd] Configuration file[/etc/frr/frr.conf] processing failure: 2
Feb 02 00:39:04 anycast frrinit.sh[35028]: line 4: % Unknown command[4]: log extended mytarget
Feb 02 00:39:04 anycast frrinit.sh[35028]: line 5: % Unknown command[4]:   destination journald
Feb 02 00:39:04 anycast frrinit.sh[35028]: [35028|zebra] Configuration file[/etc/frr/frr.conf] processing failure: 2
Feb 02 00:39:04 anycast frrinit.sh[35042]: [35042|watchfrr] sending configuration
Feb 02 00:39:04 anycast frrinit.sh[35044]: [35044|staticd] sending configuration
Feb 02 00:39:04 anycast frrinit.sh[35042]: line 4: % Unknown command[4]: log extended mytarget
Feb 02 00:39:04 anycast frrinit.sh[35042]: line 5: % Unknown command[4]:   destination journald
Feb 02 00:39:04 anycast watchfrr[34993]: [VTVCM-Y2NW3] Configuration Read in Took: 00:00:00
Feb 02 00:39:04 anycast frrinit.sh[35042]: [35042|watchfrr] Configuration file[/etc/frr/frr.conf] processing failure: 2
Feb 02 00:39:04 anycast frrinit.sh[35044]: line 4: % Unknown command[4]: log extended mytarget
Feb 02 00:39:04 anycast frrinit.sh[35044]: line 5: % Unknown command[4]:   destination journald
Feb 02 00:39:04 anycast frrinit.sh[35026]: Waiting for children to finish applying config...
Feb 02 00:39:04 anycast frrinit.sh[35044]: [35044|staticd] Configuration file[/etc/frr/frr.conf] processing failure: 2
Feb 02 00:39:04 anycast watchfrr[34993]: [ZJW5C-1EHNT] restart all process 34994 exited with non-zero status 2
Feb 02 00:39:08 anycast watchfrr[34993]: [QDG3Y-BY5TN] mgmtd state -> up : connect succeeded
Feb 02 00:39:08 anycast watchfrr[34993]: [QDG3Y-BY5TN] zebra state -> up : connect succeeded
Feb 02 00:39:09 anycast watchfrr[34993]: [QDG3Y-BY5TN] staticd state -> up : connect succeeded
Feb 02 00:39:09 anycast watchfrr[34993]: [KWE5Q-QNGFC] all daemons up, doing startup-complete notify
Feb 02 00:39:09 anycast frrinit.sh[34984]: Started watchfrr.
Feb 02 00:39:09 anycast systemd[1]: Started frr.service - FRRouting.

These log extended commands are also not available when starting an interactive vtysh.

I read the developer documentation and did some debugging, but couldn't figure out why this isn't working. clippy does find/show it as log extended-syslog, which is expected because that's what the sourcecode defines. The command matcher should still be able to correctly match it because it is still unambigious, but it doesn't. The inconsistency between doc and source exists already in the original PR. The commands are also missing from the command graph, which might indicate they are not properly registered/installed.

At least I could confirm that the described upgrade to native journald using log stdout is working.

To Reproduce

  1. Install FRR v9+ using a Debian package
  2. Adjust frr.conf to include a log extended command, like the doc suggest
  3. Start FRR as a systemd service

Expected behavior

FRR should start, and properly read and apply the "Extended Logging Target" configuration.

Versions

github-actions[bot] commented 1 month ago

This issue is stale because it has been open 180 days with no activity. Comment or remove the autoclose label in order to avoid having this issue closed.

frrbot[bot] commented 1 month ago

This issue will be automatically closed in the specified period unless there is further activity.

corubba commented 1 month ago

Issue still reproducible on Debian "bookworm" 12.6 (Kernel 6.1.0-23-amd64), with both FRR 9.1.1 and 10.0.1 from the FRR debian mirror.

frrbot[bot] commented 1 month ago

This issue will no longer be automatically closed.

Cerebus commented 13 hours ago

Also not available in 10.1.1, nor on master@HEAD as of 20 Sep 2024, on any version. Not even the official Docker images.

Cerebus commented 12 hours ago

It looks to me like the command isn't defined for vtysh at all; there's no trace of it in vtysh.c. EXTLOG_NODE is defined, DEFPY_NOSH for the node is in zlog_5424_cli.c, but there's no EXTLOG_NODE in vtysh.c.