From 206ebd9aeeb62787cb1451f04958ce2909161574 Mon Sep 17 00:00:00 2001 From: Joachim Wiberg Date: Tue, 15 Sep 2026 16:40:46 +0200 Subject: [PATCH 1/4] confd: add infix-syslog:log RPC for injecting log messages Add an infix-syslog:log RPC that hands a message to the local syslog daemon. The full RFC 5424 header is exposed: severity, facility, app-name, msgid, and structured data. Defaults follow logger(1), user.notice, with app-name defaulting to the name of the calling user. The message is time stamped on arrival and goes through the regular /syslog filtering and forwarding rules, so where it ends up is decided by the device configuration, not the caller. The handler uses syslogp_r() from the sysklogd libsyslog, which passes msgid and structured data through and sets the tag per call without touching confd's own openlog() identity. The callback's event session runs as confd, so the calling user is taken from the event originator: netopeer2 pushes it as originator data, the CLI sets it as originator name. RESTCONF sets neither, there the originator name is used as-is. Fixes #1639 Signed-off-by: Joachim Wiberg --- doc/ChangeLog.md | 6 + doc/syslog.md | 58 ++++++ package/confd/confd.mk | 2 +- src/confd/configure.ac | 1 + src/confd/src/Makefile.am | 4 +- src/confd/src/core.c | 4 + src/confd/src/core.h | 14 ++ src/confd/src/syslog.c | 191 ++++++++++++++++++ src/confd/yang/confd.inc | 2 +- src/confd/yang/confd/infix-syslog.yang | 99 +++++++++ ...1-17.yang => infix-syslog@2026-09-15.yang} | 0 11 files changed, 378 insertions(+), 3 deletions(-) rename src/confd/yang/confd/{infix-syslog@2025-11-17.yang => infix-syslog@2026-09-15.yang} (100%) diff --git a/doc/ChangeLog.md b/doc/ChangeLog.md index 543556c67..66654f51d 100644 --- a/doc/ChangeLog.md +++ b/doc/ChangeLog.md @@ -19,6 +19,12 @@ All notable changes to the project are documented in this file. ### Added +- Add a `log` RPC to `infix-syslog`, and a matching admin-exec `log` + command in the CLI, for injecting messages in the system log over + NETCONF/RESTCONF, issue #1639. The full RFC 5424 header is supported: + severity, facility, app-name, msgid, and structured data. Messages + are time stamped on arrival and follow the configured syslog filtering + and forwarding rules, like any locally generated message - Add `/system/advanced` for low-level system customization, issue #463: - `rc.d`: user scripts stored in the configuration, run once at boot after the startup configuration has been applied, in the order listed diff --git a/doc/syslog.md b/doc/syslog.md index ead621bd5..d0715ee2b 100644 --- a/doc/syslog.md +++ b/doc/syslog.md @@ -138,6 +138,64 @@ admin@example:/config/syslog/…/file:foobar/> leave admin@example:/> +## Logging Messages + +Scripts and test systems can add their own messages to the system log, +e.g., to mark the start and end of a test run. Messages are handed to +the local syslog daemon as if generated on the device: they are time +stamped on arrival and follow the same filtering and forwarding rules +as any other message. So where a message ends up, a log file, a remote +server, or both, is decided by the syslog configuration, not the +caller. + +From the CLI, the admin-exec `log` command takes the message text, with +optional `severity`, `facility`, and `msgid` keywords before it: + +
admin@example:/> log Kilroy was here
+admin@example:/> log severity warning facility daemon msgid test-start Test 42 starting
+admin@example:/> show log tail 2
+Sep 15 15:29:01 example admin: Kilroy was here
+Sep 15 15:29:07 example admin: Test 42 starting
+
+ +Over NETCONF and RESTCONF the same operation is available as the +`infix-syslog:log` RPC, which also exposes RFC 5424 structured data: + +```bash +~$ curl -k -u admin:admin -X POST \ + -H "Content-Type: application/yang-data+json" \ + https://example.local/restconf/operations/infix-syslog:log \ + -d '{"infix-syslog:input": { + "message": "Test 42 starting", + "severity": "warning", + "facility": "ietf-syslog:daemon", + "app-name": "infamy", + "msgid": "test-start", + "structured-data": [{ + "id": "test@32473", + "param": [{"name": "name", "value": "syslog/rpc_log"}] + }] + }}' +``` + +| **Field** | **Default** | **Description** | +|-------------------|--------------|--------------------------------------------------------------| +| `message` | *mandatory* | Free-form message text | +| `severity` | `notice` | Same levels as in the facility filters, `emergency`..`debug` | +| `facility` | `user` | Any facility from the table at the end of this document | +| `app-name` | calling user | RFC 5424 APP-NAME, shown as the tag in log files | +| `msgid` | none | RFC 5424 MSGID, e.g., `test-start` | +| `structured-data` | none | RFC 5424 SD elements, each an `id` with `name`/`value` params | + +In an [RFC5424][] formatted log file the message above is logged as: + +``` +2026-09-15T15:29:07.123456+02:00 example infamy - test-start [test@32473 name="syslog/rpc_log"] Test 42 starting +``` + +The `msgid` property filter, see [Property-Based Filtering](#property-based-filtering), +can be used to route such messages to a dedicated log file. + ## Log to Remote Server Logging to a remote syslog server is the recommended way of supervising diff --git a/package/confd/confd.mk b/package/confd/confd.mk index 53d2eed89..5fd3fc006 100644 --- a/package/confd/confd.mk +++ b/package/confd/confd.mk @@ -10,7 +10,7 @@ CONFD_SITE = $(BR2_EXTERNAL_INFIX_PATH)/src/confd CONFD_LICENSE = BSD-3-Clause CONFD_LICENSE_FILES = LICENSE CONFD_REDISTRIBUTE = NO -CONFD_DEPENDENCIES = host-sysrepo sysrepo rousette netopeer2 jansson libite sysrepo libsrx libglib2 libev +CONFD_DEPENDENCIES = host-sysrepo sysrepo rousette netopeer2 jansson libite sysrepo libsrx libglib2 libev sysklogd CONFD_AUTORECONF = YES CONFD_CONF_OPTS += --disable-silent-rules --with-crypt=$(BR2_PACKAGE_CONFD_DEFAULT_CRYPT) CONFD_SYSREPO_SHM_PREFIX = sr_buildroot$(subst /,_,$(CONFIG_DIR))_confd diff --git a/src/confd/configure.ac b/src/confd/configure.ac index 7747ea530..4930b00b4 100644 --- a/src/confd/configure.ac +++ b/src/confd/configure.ac @@ -110,6 +110,7 @@ PKG_CHECK_MODULES([libite], [libite >= 2.6.1]) PKG_CHECK_MODULES([sysrepo], [sysrepo >= 4.2.10]) PKG_CHECK_MODULES([libyang], [libyang >= 4.2.2]) PKG_CHECK_MODULES([libsrx], [libsrx >= 1.0.0]) +PKG_CHECK_MODULES([libsyslog], [libsyslog >= 2.7.0]) PKG_CHECK_MODULES([libcrypto], [libcrypto]) AC_CHECK_HEADER([ev.h], diff --git a/src/confd/src/Makefile.am b/src/confd/src/Makefile.am index 7e9a8b74f..d656c0c86 100644 --- a/src/confd/src/Makefile.am +++ b/src/confd/src/Makefile.am @@ -20,6 +20,7 @@ confd_plugin_la_CFLAGS = \ $(libcrypto_CFLAGS) \ $(sysrepo_CFLAGS) \ $(libsrx_CFLAGS) \ + $(libsyslog_CFLAGS) \ $(CFLAGS) confd_plugin_la_LIBADD = \ @@ -29,7 +30,8 @@ confd_plugin_la_LIBADD = \ $(libite_LIBS) \ $(libcrypto_LIBS) \ $(sysrepo_LIBS) \ - $(libsrx_LIBS) + $(libsrx_LIBS) \ + $(libsyslog_LIBS) confd_plugin_la_SOURCES = \ base64.c base64.h \ diff --git a/src/confd/src/core.c b/src/confd/src/core.c index 99fd04c14..adbf84ae1 100644 --- a/src/confd/src/core.c +++ b/src/confd/src/core.c @@ -900,6 +900,10 @@ int sr_plugin_init_cb(sr_session_ctx_t *session, void **priv) if (rc) goto err; + rc = syslog_rpc_init(&confd); + if (rc) + goto err; + /* Candidate infer configurations */ rc = interfaces_cand_init(&confd); if (rc) diff --git a/src/confd/src/core.h b/src/confd/src/core.h index 38c80873e..057a8d796 100644 --- a/src/confd/src/core.h +++ b/src/confd/src/core.h @@ -133,6 +133,10 @@ typedef enum { if ((rc = register_rpc(s, x, c, a, u))) \ goto fail +#define REGISTER_RPC_TREE(s,x,c,a,u) \ + if ((rc = register_rpc_tree(s, x, c, a, u))) \ + goto fail + struct confd { sr_session_ctx_t *session; /* running datastore */ sr_session_ctx_t *startup; /* startup datastore */ @@ -192,6 +196,15 @@ static inline int register_rpc(sr_session_ctx_t *session, const char *xpath, return rc; } +static inline int register_rpc_tree(sr_session_ctx_t *session, const char *xpath, + sr_rpc_tree_cb cb, void *arg, sr_subscription_ctx_t **sub) +{ + int rc = sr_rpc_subscribe_tree(session, xpath, cb, arg, 0, SR_SUBSCR_NO_THREAD, sub); + if (rc) + ERROR("failed subscribing to %s rpc: %s", xpath, sr_strerror(rc)); + return rc; +} + /* core.c */ int finit_enable(const char *svc); @@ -211,6 +224,7 @@ int interfaces_cand_init(struct confd *confd); /* syslog.c */ int syslog_change(sr_session_ctx_t *session, struct lyd_node *config, struct lyd_node *diff, sr_event_t event, struct confd *confd); +int syslog_rpc_init(struct confd *confd); /* system.c */ int system_rpc_init (struct confd *confd); diff --git a/src/confd/src/syslog.c b/src/confd/src/syslog.c index 8f621dce3..a9f3201c3 100644 --- a/src/confd/src/syslog.c +++ b/src/confd/src/syslog.c @@ -6,6 +6,8 @@ #include "core.h" +#include /* sysklogd syslogp_r() API */ + #define XPATH_BASE_ "/ietf-syslog:syslog" #define XPATH_FILE_ XPATH_BASE_"/actions/file" #define XPATH_LOG_FILE XPATH_BASE_"/actions/file/log-file" @@ -478,3 +480,192 @@ int syslog_change(sr_session_ctx_t *session, struct lyd_node *config, struct lyd return SR_ERR_OK; } + +/* + * RPC: /infix-syslog:log + */ + +static int log_facility(const char *name) +{ + static const struct { + const char *name; + int facility; + } map[] = { + { "kern", LOG_KERN }, + { "user", LOG_USER }, + { "mail", LOG_MAIL }, + { "daemon", LOG_DAEMON }, + { "auth", LOG_AUTH }, + { "syslog", LOG_SYSLOG }, + { "lpr", LOG_LPR }, + { "news", LOG_NEWS }, + { "uucp", LOG_UUCP }, + { "cron", LOG_CRON }, + { "authpriv", LOG_AUTHPRIV }, + { "ftp", LOG_FTP }, + { "ntp", LOG_NTP }, + { "audit", LOG_AUDIT }, + { "console", LOG_CONSOLE }, + { "cron2", LOG_CRON2 }, + { "local0", LOG_LOCAL0 }, + { "local1", LOG_LOCAL1 }, + { "local2", LOG_LOCAL2 }, + { "local3", LOG_LOCAL3 }, + { "local4", LOG_LOCAL4 }, + { "local5", LOG_LOCAL5 }, + { "local6", LOG_LOCAL6 }, + { "local7", LOG_LOCAL7 }, + /* infix-syslog local facilities */ + { "rauc", LOG_LOCAL0 }, + { "container", LOG_LOCAL1 }, + { "web", LOG_LOCAL7 }, + }; + const char *ptr; + + if (!name) + return LOG_USER; + + /* identityref, strip module prefix */ + ptr = strchr(name, ':'); + if (ptr) + name = ptr + 1; + + for (size_t i = 0; i < NELEMS(map); i++) { + if (!strcmp(map[i].name, name)) + return map[i].facility; + } + + return LOG_USER; +} + +static int log_severity(const char *name) +{ + static const char *map[] = { + "emergency", "alert", "critical", "error", + "warning", "notice", "info", "debug", + }; + + if (!name) + return LOG_NOTICE; + + for (size_t i = 0; i < NELEMS(map); i++) { + if (!strcmp(map[i], name)) + return (int)i; + } + + return LOG_NOTICE; +} + +/* + * The event session runs as confd, the calling user is only known from + * the originator: netopeer2 pushes [nc-sid, username], the CLI and the + * rpc tool set their originator name to the user. + */ +static const char *log_user(sr_session_ctx_t *session) +{ + const char *orig = sr_session_get_orig_name(session); + const void *data; + uint32_t size; + + if (orig && !strcmp(orig, "netopeer2")) { + if (!sr_session_get_orig_data(session, 1, &size, &data) && size > 1) + return data; + } + + if (orig && orig[0]) + return orig; + + return sr_session_get_user(session); +} + +/* RFC 5424 PARAM-VALUE: escape '"', '\\', and ']' */ +static char *sd_escape(char *ptr, const char *value) +{ + for (; *value; value++) { + if (*value == '"' || *value == '\\' || *value == ']') + *ptr++ = '\\'; + *ptr++ = *value; + } + + return ptr; +} + +/* Render structured-data list as [id name="value" ...][id2 ...] */ +static char *sd_build(const struct lyd_node *input) +{ + struct lyd_node *elem, *param; + char *sd, *ptr; + size_t len = 1; + + LYX_LIST_FOR_EACH(lyd_child(input), elem, "structured-data") { + len += strlen(lydx_get_cattr(elem, "id")) + 2; + LYX_LIST_FOR_EACH(lyd_child(elem), param, "param") { + len += strlen(lydx_get_cattr(param, "name")) + 4; + len += strlen(lydx_get_cattr(param, "value")) * 2; + } + } + + if (len == 1) + return NULL; + + sd = ptr = malloc(len); + if (!sd) + return NULL; + + LYX_LIST_FOR_EACH(lyd_child(input), elem, "structured-data") { + ptr += sprintf(ptr, "[%s", lydx_get_cattr(elem, "id")); + LYX_LIST_FOR_EACH(lyd_child(elem), param, "param") { + ptr += sprintf(ptr, " %s=\"", lydx_get_cattr(param, "name")); + ptr = sd_escape(ptr, lydx_get_cattr(param, "value")); + *ptr++ = '"'; + } + *ptr++ = ']'; + } + *ptr = 0; + + return sd; +} + +static int rpc_log(sr_session_ctx_t *session, uint32_t sub_id, const char *op_path, + const struct lyd_node *input, sr_event_t event, uint32_t request_id, + struct lyd_node *output, void *priv) +{ + struct syslog_data log = SYSLOG_DATA_INIT; + struct lyd_node *in = (struct lyd_node *)input; + const char *msg, *tag, *msgid; + char *sd; + int pri; + + msg = lydx_get_cattr(in, "message"); + if (!msg) + return SR_ERR_INVAL_ARG; + + pri = log_facility(lydx_get_cattr(in, "facility")) | log_severity(lydx_get_cattr(in, "severity")); + msgid = lydx_get_cattr(in, "msgid"); + tag = lydx_get_cattr(in, "app-name"); + if (!tag) + tag = log_user(session); + + log.log_tag = tag; + sd = sd_build(in); + if (sd) + syslogp_r(pri, &log, msgid, "%s", "%s", sd, msg); + else + syslogp_r(pri, &log, msgid, NULL, "%s", msg); + closelog_r(&log); + free(sd); + + return SR_ERR_OK; +} + +int syslog_rpc_init(struct confd *confd) +{ + int rc; + + REGISTER_RPC_TREE(confd->session, "/infix-syslog:log", rpc_log, NULL, &confd->sub); + + return SR_ERR_OK; +fail: + ERROR("init failed: %s", sr_strerror(rc)); + return rc; +} diff --git a/src/confd/yang/confd.inc b/src/confd/yang/confd.inc index 62ba37b9d..ff12f884d 100644 --- a/src/confd/yang/confd.inc +++ b/src/confd/yang/confd.inc @@ -24,7 +24,7 @@ MODULES=( # NOTE: ietf-tls-client must be version matched with ietf-tls-server, used by netopeer2! # "ietf-tls-client@2023-12-28.yang" "ietf-syslog@2024-03-21.yang -e file-action -e file-limit-size -e remote-action -e select-adv-compare -e select-match" - "infix-syslog@2025-11-17.yang" + "infix-syslog@2026-09-15.yang" "iana-hardware@2018-03-13.yang" "ietf-hardware@2018-03-13.yang -e hardware-state -e hardware-sensor" "infix-hardware@2026-07-02.yang" diff --git a/src/confd/yang/confd/infix-syslog.yang b/src/confd/yang/confd/infix-syslog.yang index 981f498d8..394b94146 100644 --- a/src/confd/yang/confd/infix-syslog.yang +++ b/src/confd/yang/confd/infix-syslog.yang @@ -16,6 +16,11 @@ module infix-syslog { contact "kernelkit@googlegroups.com"; description "Infix augments and deviations to ietf-syslog, draft 32."; + revision 2026-09-15 { + description "Add log RPC for injecting messages in the system log."; + reference "internal"; + } + revision 2025-11-17 { description "Add hostname-filter support."; reference "internal"; @@ -77,6 +82,19 @@ module infix-syslog { description "Latest format, better time granularity, structured data, etc."; } + /* + * Typedefs + */ + + typedef sd-name { + type string { + length "1..32"; + pattern '[!#-<>-\\^-~]+'; + } + description "RFC 5424 SD-NAME: printable US-ASCII, except '=', ']', and '\"'."; + reference "RFC 5424: The Syslog Protocol, Section 6.3.2"; + } + /* * Shared settings */ @@ -285,4 +303,85 @@ module infix-syslog { description "Not yet supported by underlying daemon."; deviate not-supported; } + + /* + * RPCs + */ + + rpc log { + description "Log a message via the local system logger. + + The message is handed to the system log daemon like any + locally generated message, i.e., it is time stamped on + arrival and subject to the same filtering and forwarding + rules as configured in /syslog."; + reference "RFC 5424: The Syslog Protocol"; + + input { + leaf message { + type string { + length "1..2048"; + } + mandatory true; + description "Free-form message text."; + } + + leaf severity { + type syslog:syslog-severity; + default notice; + description "Message severity."; + } + + leaf facility { + type identityref { + base syslog:syslog-facility; + } + default syslog:user; + description "Message facility."; + } + + leaf app-name { + type string { + length "1..48"; + pattern '[!-~]+'; + } + description "Originating application name, or tag, RFC 5424 APP-NAME. + Default: name of the calling user."; + } + + leaf msgid { + type string { + length "1..32"; + pattern '[!-~]+'; + } + description "Message type identifier, RFC 5424 MSGID, e.g., 'test-start'."; + } + + list structured-data { + key "id"; + description "RFC 5424 structured data, rendered as [id name=\"value\" ...]."; + + leaf id { + type sd-name; + description "SD-ID, private identifiers use the form name@enterprise-number."; + } + + list param { + key "name"; + description "SD-PARAM, name and value pair."; + + leaf name { + type sd-name; + description "Parameter name."; + } + + leaf value { + type string; + mandatory true; + description "Parameter value, any '\"', '\\', and ']' are escaped on output."; + } + } + } + } + } } diff --git a/src/confd/yang/confd/infix-syslog@2025-11-17.yang b/src/confd/yang/confd/infix-syslog@2026-09-15.yang similarity index 100% rename from src/confd/yang/confd/infix-syslog@2025-11-17.yang rename to src/confd/yang/confd/infix-syslog@2026-09-15.yang From 53c1d460d68b369c9efddb153225b55dd7a4f26e Mon Sep 17 00:00:00 2001 From: Joachim Wiberg Date: Tue, 15 Sep 2026 16:40:47 +0200 Subject: [PATCH 2/4] cli: add admin-exec log command Front-end to the infix-syslog:log RPC. Optional severity, facility, and msgid keywords precede the message, which is the rest of the line: admin@example:/> log severity warning msgid test-start Test 42 starting Two fixes to the rpc tool the command is built on. It now sets the session originator name to the calling user, like klish-plugin-sysrepo, so the RPC can default app-name to the user. And it only splits comma-separated values for leaf-lists, previously any leaf value with a comma became two instances and the RPC failed: $ rpc /infix-syslog:log message "Kilroy was here, again" Issue #1639 Signed-off-by: Joachim Wiberg --- src/bin/copy.c | 26 ++++++++-- src/klish-plugin-infix/xml/infix.xml | 75 ++++++++++++++++++++++++++++ 2 files changed, 98 insertions(+), 3 deletions(-) diff --git a/src/bin/copy.c b/src/bin/copy.c index 2fcc8584a..177b04071 100644 --- a/src/bin/copy.c +++ b/src/bin/copy.c @@ -12,6 +12,7 @@ #include #include +#include #include #include #include @@ -341,6 +342,9 @@ static int sysrepo_init(sr_conn_ctx_t **conn, sr_session_ctx_t **sess, goto fail; } + /* Like klish-plugin-sysrepo, lets RPC callbacks see who called */ + sr_session_set_orig_name(*sess, user); + return SR_ERR_OK; fail: sysrepo_print_error(*sess); @@ -859,7 +863,7 @@ static int usage_rpc(int rc) "Arguments:\n" " rpc-xpath RPC XPath (e.g., /ietf-system:set-current-datetime)\n" " key value Pairs of RPC argument names and values\n" - " Values can be comma-separated for lists/leaf-lists\n" + " Leaf-list values can be comma-separated\n" "\n" "Examples:\n" " %s /ietf-system:set-current-datetime current-datetime \"2025-01-01T00:00:00Z\"\n" @@ -870,6 +874,22 @@ static int usage_rpc(int rc) return rc; } +static bool is_leaflist(sr_conn_ctx_t *conn, const char *rpc_xpath, const char *key) +{ + char xpath[strlen(rpc_xpath) + strlen(key) + 2]; + const struct lysc_node *node; + const struct ly_ctx *ctx; + bool rc; + + snprintf(xpath, sizeof(xpath), "%s/%s", rpc_xpath, key); + ctx = sr_acquire_context(conn); + node = lys_find_path(ctx, NULL, xpath, 0); + rc = node && node->nodetype == LYS_LEAFLIST; + sr_release_context(conn); + + return rc; +} + /* Execute RPC from CLI arguments: xpath and key-value pairs */ static int rpc_exec(const char *rpc_xpath, int argc, char *argv[]) { @@ -892,8 +912,8 @@ static int rpc_exec(const char *rpc_xpath, int argc, char *argv[]) const char *val = argv[i + 1]; char *val_copy, *token, *saveptr; - /* Check if value contains commas - split into multiple values */ - if (strchr(val, ',')) { + /* Comma-separated values are only a list for leaf-lists */ + if (strchr(val, ',') && is_leaflist(conn, rpc_xpath, key)) { val_copy = strdup(val); if (!val_copy) { warnx("Memory allocation failed"); diff --git a/src/klish-plugin-infix/xml/infix.xml b/src/klish-plugin-infix/xml/infix.xml index 60b8f670a..8196192f8 100644 --- a/src/klish-plugin-infix/xml/infix.xml +++ b/src/klish-plugin-infix/xml/infix.xml @@ -227,6 +227,81 @@ + + + + + + emergency + alert + critical + error + warning + notice + info + debug + + + + + + + auth + authpriv + console + cron + daemon + ftp + kern + local0 + local1 + local2 + local3 + local4 + local5 + local6 + local7 + lpr + mail + news + ntp + syslog + user + uucp + + + + + + + + + + set -- /infix-syslog:log + if [ -n "$KLISH_PARAM_severity" ]; then + set -- "$@" severity "$KLISH_PARAM_severity" + fi + if [ -n "$KLISH_PARAM_msgid" ]; then + set -- "$@" msgid "$KLISH_PARAM_msgid" + fi + if [ -n "$KLISH_PARAM_facility" ]; then + case "$KLISH_PARAM_facility" in + rauc|container|web) set -- "$@" facility "infix-syslog:$KLISH_PARAM_facility" ;; + *) set -- "$@" facility "ietf-syslog:$KLISH_PARAM_facility" ;; + esac + fi + msg="" + i=0 + while :; do + eval "word=\${KLISH_PARAM_message_$i}" + [ -n "$word" ] || break + msg="${msg:+$msg }$word" + i=$((i + 1)) + done + rpc "$@" message "$msg" + + + /ietf-system:system-shutdown From 2079abbf69b5b4fbd4ba5639376a841eb14f4a88 Mon Sep 17 00:00:00 2001 From: Joachim Wiberg Date: Tue, 15 Sep 2026 16:40:48 +0200 Subject: [PATCH 3/4] test/infamy: add Transport.log(), log messages using RPC Wrap the infix-syslog:log RPC so tests can leave markers in a DUT's system log over the management API instead of SSH and logger(1). Facility names are module-qualified in the helper, and structured data is given as a dict of dicts to keep call sites short. The RESTCONF backend's call_dict() only tracked coverage and returned without sending anything, so RPCs with input silently did nothing over RESTCONF. POST to /restconf/operations/MODULE:NAME with the input wrapped per RFC 8040, like call_action() does. Convert the tests that logged via SSH. The remote and hostname_filter tests keep using logger(1), they deliberately exercise the remote client path. Signed-off-by: Joachim Wiberg --- .../services/mdns/mdns_allow_deny/test.py | 2 +- test/case/syslog/advanced_compare/test.py | 20 +++++++------- test/case/syslog/pattern_match/test.py | 2 +- test/case/syslog/property_filter/test.py | 2 +- test/infamy/restconf.py | 18 ++++++++++++- test/infamy/transport.py | 27 +++++++++++++++++++ 6 files changed, 57 insertions(+), 14 deletions(-) diff --git a/test/case/services/mdns/mdns_allow_deny/test.py b/test/case/services/mdns/mdns_allow_deny/test.py index 6feea7cbf..5fb6ab986 100755 --- a/test/case/services/mdns/mdns_allow_deny/test.py +++ b/test/case/services/mdns/mdns_allow_deny/test.py @@ -22,7 +22,7 @@ def mdns_scan(): pcap3 = ns3.pcap("host 10.0.3.1 and port 5353") with pcap1, pcap2, pcap3: - ssh.runsh("logger -t scan 'calling avahi-browse ...'") + dut.log("calling avahi-browse ...", app_name="scan") ssh.runsh("avahi-browse -lat") def has_packets(output): diff --git a/test/case/syslog/advanced_compare/test.py b/test/case/syslog/advanced_compare/test.py index c83bbe657..d82584e24 100755 --- a/test/case/syslog/advanced_compare/test.py +++ b/test/case/syslog/advanced_compare/test.py @@ -11,14 +11,14 @@ from infamy.util import parallel, until TEST_MESSAGES = [ - ("daemon.emerg", "Emergency: system is unusable"), - ("daemon.alert", "Alert: immediate action required"), - ("daemon.crit", "Critical: critical condition"), - ("daemon.err", "Error: error condition"), - ("daemon.warning", "Warning: warning condition"), - ("daemon.notice", "Notice: normal but significant"), - ("daemon.info", "Info: informational message"), - ("daemon.debug", "Debug: debug-level message"), + ("emergency", "Emergency: system is unusable"), + ("alert", "Alert: immediate action required"), + ("critical", "Critical: critical condition"), + ("error", "Error: error condition"), + ("warning", "Warning: warning condition"), + ("notice", "Notice: normal but significant"), + ("info", "Info: informational message"), + ("debug", "Debug: debug-level message"), ] with infamy.Test() as test: @@ -76,8 +76,8 @@ until(lambda: tgtssh.runsh("test -f /var/log/exact-errors").returncode == 0, attempts=10) with test.step("Send test messages at all severity levels"): - for priority, message in TEST_MESSAGES: - tgtssh.runsh(f"logger -t advtest -p {priority} '{message}'") + for severity, message in TEST_MESSAGES: + target.log(message, severity=severity, facility="daemon", app_name="advtest") until(lambda: "Error: error condition" in tgtssh.runsh("cat /var/log/exact-errors 2>/dev/null").stdout, attempts=10) with test.step("Verify exact-errors log contains only error messages"): diff --git a/test/case/syslog/pattern_match/test.py b/test/case/syslog/pattern_match/test.py index daf046a8a..4328788ae 100755 --- a/test/case/syslog/pattern_match/test.py +++ b/test/case/syslog/pattern_match/test.py @@ -66,7 +66,7 @@ with test.step("Send test messages with various patterns"): for message in TEST_MESSAGES: - tgtssh.runsh(f"logger -t test -p daemon.info '{message}'") + target.log(message, severity="info", facility="daemon", app_name="test") time.sleep(2) with test.step("Verify errors log contains ERROR and CRITICAL messages"): diff --git a/test/case/syslog/property_filter/test.py b/test/case/syslog/property_filter/test.py index 7f7d7fd9d..e0c55bff0 100755 --- a/test/case/syslog/property_filter/test.py +++ b/test/case/syslog/property_filter/test.py @@ -94,7 +94,7 @@ with test.step("Send test messages"): for tag, msg in TEST_MESSAGES: - tgtssh.runsh(f"logger -t {tag} -p daemon.info '{msg}'") + target.log(msg, severity="info", facility="daemon", app_name=tag) until(lambda: "Application startup" in tgtssh.runsh("cat /var/log/baseline 2>/dev/null").stdout, attempts=10) with test.step("Verify myapp log contains only myapp messages"): diff --git a/test/infamy/restconf.py b/test/infamy/restconf.py index ad004a8dc..1fe45343b 100644 --- a/test/infamy/restconf.py +++ b/test/infamy/restconf.py @@ -411,8 +411,24 @@ def patch_config(self, xpath, edit, retries=3): raise last_error def call_dict(self, model, call): + """Call RPC, Python dictionary version: {"rpc-name": {input leaves}}""" coverage.track_dict(model, call) - pass # Need implementation + if len(call) != 1: + raise ValueError("call_dict() expects a single RPC: {name: input}") + + (name, data), = call.items() + url = f"{self.rpc_url}/{model}:{name}" + body = {f"{model}:input": data} if data else None + response = requests_workaround_post( + url, + json=body, + headers=self.headers, + auth=self.auth, + verify=False + ) + response.raise_for_status() + + return response.content def call_rpc(self, rpc): """Actually send a POST to RESTCONF server""" diff --git a/test/infamy/transport.py b/test/infamy/transport.py index fec58fd5c..5b89d78fb 100644 --- a/test/infamy/transport.py +++ b/test/infamy/transport.py @@ -107,3 +107,30 @@ def test_reset(self): def startup_override(self): self.call_action("/infix-test:test/override-startup") + + def log(self, message, severity=None, facility=None, app_name=None, + msgid=None, sd=None): + """Log a message on the target, using the infix-syslog:log RPC. + + Defaults to user.notice with app-name set to the calling user. + `facility` is a plain name, e.g. "daemon", the module prefix is + added here. `sd` is RFC 5424 structured data, given as a dict + of dicts: {"sd-id": {"name": "value", ...}}. + """ + rpc = {"message": message} + if severity: + rpc["severity"] = severity + if facility: + module = "infix-syslog" if facility in ("rauc", "container", "web") else "ietf-syslog" + rpc["facility"] = f"{module}:{facility}" + if app_name: + rpc["app-name"] = app_name + if msgid: + rpc["msgid"] = msgid + if sd: + rpc["structured-data"] = [{ + "id": sdid, + "param": [{"name": name, "value": value} for name, value in params.items()] + } for sdid, params in sd.items()] + + return self.call_dict("infix-syslog", {"log": rpc}) From 2ad2348851aaca0ff79cfb41746ede49f6461051 Mon Sep 17 00:00:00 2001 From: Joachim Wiberg Date: Tue, 15 Sep 2026 16:40:49 +0200 Subject: [PATCH 4/4] test: syslog: new test, rpc_log, verify infix-syslog:log RPC Log to an RFC 5424 formatted file and check app-name, msgid, and structured data land in the header, and that a bare message gets the default app-name with empty msgid and structured data. Signed-off-by: Joachim Wiberg --- test/case/syslog/all.yaml | 3 + test/case/syslog/rpc_log/Readme.adoc | 1 + test/case/syslog/rpc_log/test.adoc | 27 +++++++++ test/case/syslog/rpc_log/test.py | 83 +++++++++++++++++++++++++++ test/case/syslog/rpc_log/topology.dot | 23 ++++++++ test/case/syslog/rpc_log/topology.svg | 33 +++++++++++ 6 files changed, 170 insertions(+) create mode 120000 test/case/syslog/rpc_log/Readme.adoc create mode 100644 test/case/syslog/rpc_log/test.adoc create mode 100755 test/case/syslog/rpc_log/test.py create mode 100644 test/case/syslog/rpc_log/topology.dot create mode 100644 test/case/syslog/rpc_log/topology.svg diff --git a/test/case/syslog/all.yaml b/test/case/syslog/all.yaml index 01be9dd42..e6d6853a9 100644 --- a/test/case/syslog/all.yaml +++ b/test/case/syslog/all.yaml @@ -16,3 +16,6 @@ - name: Syslog Property Filtering case: property_filter/test.py + +- name: Syslog Log RPC + case: rpc_log/test.py diff --git a/test/case/syslog/rpc_log/Readme.adoc b/test/case/syslog/rpc_log/Readme.adoc new file mode 120000 index 000000000..ae32c8412 --- /dev/null +++ b/test/case/syslog/rpc_log/Readme.adoc @@ -0,0 +1 @@ +test.adoc \ No newline at end of file diff --git a/test/case/syslog/rpc_log/test.adoc b/test/case/syslog/rpc_log/test.adoc new file mode 100644 index 000000000..7f056cb23 --- /dev/null +++ b/test/case/syslog/rpc_log/test.adoc @@ -0,0 +1,27 @@ +=== Syslog Log RPC + +ifdef::topdoc[:imagesdir: {topdoc}../../test/case/syslog/rpc_log] + +==== Description + +Verify the infix-syslog:log RPC, used by the test system to inject +markers in a DUT's system log. A message logged with the full RFC 5424 +header must show up in an RFC 5424 formatted log file with the given +app-name, msgid, and structured data. A message logged with only the +mandatory text must fall back to the documented defaults. + +==== Topology + +image::topology.svg[Syslog Log RPC topology, align=center, scaledwidth=75%] + +==== Sequence + +. Set up topology and attach to target DUT +. Clean up old log file from previous test runs +. Configure an RFC 5424 formatted log file for all facilities +. Log message with severity, facility, app-name, msgid, and structured data +. Verify RFC 5424 header fields of the logged message +. Log message with only the mandatory text +. Verify default app-name is set and msgid and structured data are empty + + diff --git a/test/case/syslog/rpc_log/test.py b/test/case/syslog/rpc_log/test.py new file mode 100755 index 000000000..2026694ab --- /dev/null +++ b/test/case/syslog/rpc_log/test.py @@ -0,0 +1,83 @@ +#!/usr/bin/env python3 +"""Syslog Log RPC + +Verify the infix-syslog:log RPC, used by the test system to inject +markers in a DUT's system log. A message logged with the full RFC 5424 +header must show up in an RFC 5424 formatted log file with the given +app-name, msgid, and structured data. A message logged with only the +mandatory text must fall back to the documented defaults. + +""" + +import re + +import infamy +from infamy.util import parallel, until + +LOG_FILE = "/var/log/rpc-log" + + +def logfile(): + """Return contents of the RFC 5424 test log file, or empty string""" + rc = tgtssh.runsh(f"cat {LOG_FILE} 2>/dev/null") + return rc.stdout if rc.returncode == 0 else "" + + +with infamy.Test() as test: + with test.step("Set up topology and attach to target DUT"): + env = infamy.Env() + target, tgtssh = parallel(lambda: env.attach("target", "mgmt"), + lambda: env.attach("target", "mgmt", "ssh")) + + with test.step("Clean up old log file from previous test runs"): + tgtssh.runsh(f"sudo rm -f {LOG_FILE}") + + with test.step("Configure an RFC 5424 formatted log file for all facilities"): + target.put_config_dicts({ + "ietf-syslog": { + "syslog": { + "actions": { + "file": { + "log-file": [{ + "name": f"file:{LOG_FILE}", + "infix-syslog:log-format": "rfc5424", + "facility-filter": { + "facility-list": [{ + "facility": "all", + "severity": "info" + }] + } + }] + } + } + } + } + }) + until(lambda: tgtssh.runsh(f"test -f {LOG_FILE}").returncode == 0, attempts=10) + + with test.step("Log message with severity, facility, app-name, msgid, and structured data"): + target.log("Kilroy was here", severity="warning", facility="daemon", + app_name="infamy", msgid="test-start", + sd={"test@32473": {"name": "rpc_log", "step": "3"}}) + until(lambda: "Kilroy was here" in logfile(), attempts=10) + + with test.step("Verify RFC 5424 header fields of the logged message"): + line = [ln for ln in logfile().splitlines() if "Kilroy was here" in ln][0] + if not re.search(r"\binfamy - test-start \[test@32473 [^]]*\] Kilroy was here$", line): + test.fail(f"Unexpected app-name, msgid, or structured data: {line}") + for param in ('name="rpc_log"', 'step="3"'): + if param not in line: + test.fail(f"Missing structured data param {param}: {line}") + + with test.step("Log message with only the mandatory text"): + target.log("Plain message, no frills") + until(lambda: "Plain message" in logfile(), attempts=10) + + with test.step("Verify default app-name is set and msgid and structured data are empty"): + line = [ln for ln in logfile().splitlines() if "Plain message" in ln][0] + if not re.search(r" \S+ - - - Plain message, no frills$", line): + test.fail(f"Unexpected header for default message: {line}") + if re.search(r" - - - - Plain message", line): + test.fail(f"Default app-name should not be empty: {line}") + + test.succeed() diff --git a/test/case/syslog/rpc_log/topology.dot b/test/case/syslog/rpc_log/topology.dot new file mode 100644 index 000000000..e6a0d803b --- /dev/null +++ b/test/case/syslog/rpc_log/topology.dot @@ -0,0 +1,23 @@ +graph "1x1" { + layout="neato"; + overlap="false"; + esep="+80"; + + node [shape=record, fontname="DejaVu Sans Mono, Book"]; + edge [color="cornflowerblue", penwidth="2", fontname="DejaVu Serif, Book"]; + + host [ + label="host | { mgmt }", + pos="0,12!", + requires="controller", + ]; + + target [ + label="{ mgmt } | target", + pos="10,12!", + + requires="infix", + ]; + + host:mgmt -- target:mgmt [requires="mgmt", color="lightgray"] +} diff --git a/test/case/syslog/rpc_log/topology.svg b/test/case/syslog/rpc_log/topology.svg new file mode 100644 index 000000000..6fc6f47a8 --- /dev/null +++ b/test/case/syslog/rpc_log/topology.svg @@ -0,0 +1,33 @@ + + + + + + +1x1 + + + +host + +host + +mgmt + + + +target + +mgmt + +target + + + +host:mgmt--target:mgmt + + + +