[Devel] [PATCH vz10] tests: add ve_printk selftest
Konstantin Khorenko
khorenko at virtuozzo.com
Tue Dec 2 13:32:57 MSK 2025
On 11/26/25 21:04, Aleksei Oladko wrote:
> Add selftests for the printk virtualization feature. The new tests cover
> ve_printk, ve_printk_ratelimited, net_ve_ratelimited, and log buffer
> overflow handling.
>
> https://virtuozzo.atlassian.net/browse/VSTOR-114252
>
> Signed-off-by: Aleksei Oladko <aleksey.oladko at virtuozzo.com>
> ---
> tools/testing/selftests/Makefile | 1 +
> tools/testing/selftests/ve_printk/.gitignore | 3 +
> tools/testing/selftests/ve_printk/Makefile | 8 +
> tools/testing/selftests/ve_printk/test_segf.c | 12 +
> tools/testing/selftests/ve_printk/test_trap.c | 5 +
> .../selftests/ve_printk/ve_printk_test.c | 593 ++++++++++++++++++
> 6 files changed, 622 insertions(+)
> create mode 100644 tools/testing/selftests/ve_printk/.gitignore
> create mode 100644 tools/testing/selftests/ve_printk/Makefile
> create mode 100644 tools/testing/selftests/ve_printk/test_segf.c
> create mode 100644 tools/testing/selftests/ve_printk/test_trap.c
> create mode 100644 tools/testing/selftests/ve_printk/ve_printk_test.c
>
> diff --git a/tools/testing/selftests/Makefile b/tools/testing/selftests/Makefile
> index 363d031a16f7..7334fb207676 100644
> --- a/tools/testing/selftests/Makefile
> +++ b/tools/testing/selftests/Makefile
> @@ -113,6 +113,7 @@ TARGETS += tty
> TARGETS += uevent
> TARGETS += user_events
> TARGETS += vDSO
> +TARGETS += ve_printk
> TARGETS += mm
> TARGETS += x86
> TARGETS += zram
> diff --git a/tools/testing/selftests/ve_printk/.gitignore b/tools/testing/selftests/ve_printk/.gitignore
> new file mode 100644
> index 000000000000..a4ad6620b803
> --- /dev/null
> +++ b/tools/testing/selftests/ve_printk/.gitignore
> @@ -0,0 +1,3 @@
> +ve_printk_test
> +test_segf
> +test_trap
> diff --git a/tools/testing/selftests/ve_printk/Makefile b/tools/testing/selftests/ve_printk/Makefile
> new file mode 100644
> index 000000000000..e3edcbacda1e
> --- /dev/null
> +++ b/tools/testing/selftests/ve_printk/Makefile
> @@ -0,0 +1,8 @@
> +# SPDX-License-Identifier: GPL-2.0
> +# Makefile for ve_printk selftests.
> +CFLAGS = -g -I../../../../usr/include/ -Wall -O2
> +
> +TEST_GEN_PROGS += ve_printk_test
> +TEST_GEN_FILES += test_segf test_trap
> +
> +include ../lib.mk
> diff --git a/tools/testing/selftests/ve_printk/test_segf.c b/tools/testing/selftests/ve_printk/test_segf.c
> new file mode 100644
> index 000000000000..cdc89068ca06
> --- /dev/null
> +++ b/tools/testing/selftests/ve_printk/test_segf.c
> @@ -0,0 +1,12 @@
> +#include <stdio.h>
> +#include <unistd.h>
> +
> +int main(void)
> +{
> + int *p = (int *)0xffffffffffffff00;
> +
> + printf("%d\n", getpid());
> + fflush(stdout);
> + *p = 1;
> + return 0;
> +}
> diff --git a/tools/testing/selftests/ve_printk/test_trap.c b/tools/testing/selftests/ve_printk/test_trap.c
> new file mode 100644
> index 000000000000..b774e2b9484c
> --- /dev/null
> +++ b/tools/testing/selftests/ve_printk/test_trap.c
> @@ -0,0 +1,5 @@
> +int main(void)
> +{
> + __asm__("int3");
> + return 0;
> +}
> diff --git a/tools/testing/selftests/ve_printk/ve_printk_test.c b/tools/testing/selftests/ve_printk/ve_printk_test.c
> new file mode 100644
> index 000000000000..78475ff71faa
> --- /dev/null
> +++ b/tools/testing/selftests/ve_printk/ve_printk_test.c
> @@ -0,0 +1,593 @@
> +// SPDX-License-Identifier: GPL-2.0
> +#define _GNU_SOURCE
> +#include <linux/sched.h>
> +#include <time.h>
> +#include <sched.h>
> +#include <sys/wait.h>
> +#include <unistd.h>
> +#include <stdio.h>
> +#include <stdlib.h>
> +#include <fcntl.h>
> +#include <string.h>
> +#include <sys/stat.h>
> +#include <sys/mount.h>
> +#include <linux/limits.h>
> +#include <errno.h>
> +
> +#include "../kselftest_harness.h"
> +
> +#define __STACK_SIZE (8 * 1024 * 1024)
> +#define CTID_MIN 108
> +#define CTID_MAX 200
> +#define SEGFAULT_PROG "test_segf"
> +#define TRAP_PROG "test_trap"
> +#define TEST_RATELIMIT_BURST 10
> +#define TEST_RATELIMIT 5
> +
> +static int has_substr(char *buf, const char *str)
> +{
> + char *token;
> + char *str_ptr = buf;
> +
> + while ((token = strsep(&str_ptr, ",")) != NULL) {
> + if (!strcmp(token, str))
> + return 1;
> + }
> + return 0;
> +}
> +
> +static int get_mount_path(const char *fstype, const char *subsys, char *out, int size)
> +{
> + FILE *fp;
> + int n;
> + char buf[PATH_MAX];
> + char target[4096];
> + char ops[4096];
> + char format[4096];
> + int ret = 1;
> +
> + snprintf(format, sizeof(format), "%%*s %%4095s %s %%4095s", fstype);
> +
> + fp = fopen("/proc/mounts", "r");
> + if (fp == NULL)
> + return -1;
> +
> + while (fgets(buf, sizeof(buf), fp)) {
> + n = sscanf(buf, format, target, ops);
> + if (n != 2)
> + continue;
> + if (subsys == NULL || has_substr(ops, subsys)) {
> + strncpy(out, target, size);
> + out[size-1] = '\0';
> + ret = 0;
> + break;
> + }
> + }
> + fclose(fp);
> +
> + return ret;
> +}
> +
> +FIXTURE(ve_printk)
> +{
> + char cgv2_path[PATH_MAX];
> + char cgve_path[PATH_MAX];
> + int ctid;
> +};
> +
> +FIXTURE_SETUP(ve_printk)
> +{
> + char path[PATH_MAX * 2];
> +
> + ASSERT_EQ(get_mount_path("cgroup2", NULL, self->cgv2_path, sizeof(self->cgv2_path)), 0);
> + ASSERT_EQ(get_mount_path("cgroup", "ve", self->cgve_path, sizeof(self->cgve_path)), 0);
> +
> + self->ctid = CTID_MIN;
> + while (self->ctid < CTID_MAX) {
> + snprintf(path, sizeof(path), "%s/%d", self->cgve_path, self->ctid);
> + if (access(path, F_OK) && errno == ENOENT) {
> + snprintf(path, sizeof(path), "%s/%d", self->cgv2_path, self->ctid);
> + if (access(path, F_OK)) {
> + break;
> + }
> + }
> + self->ctid++;
> + }
> + ASSERT_LT(self->ctid, CTID_MAX);
> +
> + snprintf(path, sizeof(path), "%s/%d", self->cgv2_path, self->ctid);
> + ASSERT_EQ(mkdir(path, 0755), 0);
> + snprintf(path, sizeof(path), "%s/%d", self->cgve_path, self->ctid);
> + ASSERT_EQ(mkdir(path, 0755), 0);
> + snprintf(path, sizeof(path), "echo %d > %s/%d/ve.veid",
> + self->ctid, self->cgve_path, self->ctid);
> + ASSERT_EQ(system(path), 0);
> +};
> +
> +FIXTURE_TEARDOWN(ve_printk)
> +{
> + char path[PATH_MAX * 2];
> +
> + snprintf(path, sizeof(path), "%s/%d/vz.slice", self->cgv2_path, self->ctid);
> + rmdir(path);
> + snprintf(path, sizeof(path), "%s/%d", self->cgv2_path, self->ctid);
> + rmdir(path);
> + snprintf(path, sizeof(path), "%s/%d", self->cgve_path, self->ctid);
> + rmdir(path);
> +}
> +
> +int setup_timens(void)
> +{
> + int ret, fd;
> +
> + if (access("/proc/self/timens_offsets", F_OK))
> + return 0;
> +
> + if (unshare(CLONE_NEWTIME)) {
> + return -1;
> + }
> +
> + fd = open("/proc/self/ns/time_for_children", O_RDONLY);
> + if (fd < 0) {
> + return -1;
> + }
> +
> + ret = setns(fd, CLONE_NEWTIME);
> +
> + close(fd);
> + return ret;
> +}
> +
> +struct fargs {
> + char *cgve;
> + int ctid;
> + int test;
> +};
> +
> +enum {
> + TEST_LOG,
> + TEST_LOGV0,
> + TEST_LOGBOTH,
> + TEST_PR_RATELIMIT,
> + TEST_OVERFLOW,
> +};
> +
> +int ve_printk_test_logct(void)
> +{
> + FILE *pdmesg;
> + char buf[1024];
> + char str[256];
> + FILE *f;
> + int pid;
> + int ret = 2;
> +
> + f = popen("./" SEGFAULT_PROG, "r");
> + if (!f)
> + return -1;
> +
> + if (fscanf(f, "%d", &pid) != 1) {
> + pclose(f);
> + return -1;
> + }
> + pclose(f);
> +
> + pdmesg = popen("dmesg", "r");
> + if (!pdmesg)
> + return -1;
> +
> + snprintf(str, sizeof(str), "%s[%d]: segfault at", SEGFAULT_PROG, pid);
> + while (fgets(buf, sizeof(buf), pdmesg)) {
> + if (ret == 2 && strstr(buf, str)) {
> + ret = 1;
> + }
> + if (ret == 1 && strstr(buf, "Code: ")) {
> + ret = 0;
> + break;
> + }
> + }
> + pclose(pdmesg);
> + return ret;
> +}
> +
> +int ve_printk_test_logve0(void)
> +{
> + FILE *pdmesg;
> + char buf[1024];
> + int ret = 0;
> +
> + /* do_trap -> show_signal -> print_vma_addr -> ve_print_vma_addr(VE0_LOG, ... */
> + system("./" TRAP_PROG);
> +
> + pdmesg = popen("dmesg", "r");
> + if (!pdmesg)
> + return -1;
> +
> + while (fgets(buf, sizeof(buf), pdmesg)) {
> + if (strstr(buf, "traps: test_trap[") &&
> + strstr(buf, " in test_trap[")) {
> + ret = 1;
> + break;
> + }
> + }
> + pclose(pdmesg);
> + return ret;
> +}
> +
> +int ve_printk_test_logboth(void)
> +{
> + FILE *pdmesg;
> + char buf[1024];
> + int ret = TEST_RATELIMIT_BURST;
> +
> + system("ip link set up dev lo");
> + /*
> + * Reduce the connection tracking table size to 2. After two ping calls the
> + * table will be full, and all new packets will trigger
> + * net_veboth_ratelimited
> + */
> + system("echo 2 > /proc/sys/net/nf_conntrack_max");
Restore nf_conntrack_max after the test.
> + system("iptables -A INPUT -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT");
Please cleanup those rules after the test.
> + system("ping -q -c 1 -w 1 127.0.0.1 > /dev/null");
> + system("ping -q -c 1 -w 1 127.0.0.1 > /dev/null");
> + /* net_veboth_ratelimited */
> + system("ping -q -c 100 -w 1 -i 0.0001 127.0.0.1 > /dev/null");
> +
> + pdmesg = popen("dmesg", "r");
> + if (!pdmesg)
> + return -1;
> +
> + while (fgets(buf, sizeof(buf), pdmesg)) {
> + if (strstr(buf, "nf_conntrack table full, dropping packet")) {
> + ret--;
> + }
> + }
> + pclose(pdmesg);
> + return ret;
> +}
> +
> +int ve_printk_test_ratelimit(void)
> +{
> + FILE *pdmesg;
> + char buf[1024];
> + int ret = TEST_RATELIMIT_BURST + 1;
> + int supressed = 1;
> + int i;
> +
> + /* reject_tg_check -> ve_printk_ratelimited(VE_LOG, ... */
> + for (i = 0; i < 2 * TEST_RATELIMIT_BURST; i++) {
> + system("iptables -A INPUT -s 10.20.30.40 -j REJECT --reject-with tcp-reset &> /dev/null");
Please cleanup those rules after the test.
> + }
> + sleep(TEST_RATELIMIT + 1);
> + system("iptables -A INPUT -s 10.20.30.40 -j REJECT --reject-with tcp-reset &> /dev/null");
Please cleanup those rules after the test.
BTW, here we have many "system" calls and none ret checks.
In the meanwhile even iptables may be easily missing.
i think need to add a wrapper which checks err code after system().
> +
> + pdmesg = popen("dmesg", "r");
> + if (!pdmesg)
> + return -1;
> +
> + while (fgets(buf, sizeof(buf), pdmesg)) {
> + if (strstr(buf, "TCP_RESET invalid for non-tcp")) {
> + ret--;
> + }
> + if (strstr(buf, "reject_tg_check") && strstr(buf, "callbacks suppressed"))
> + supressed--;
> + }
> + pclose(pdmesg);
> +
> + return ret + supressed;
> +}
> +
> +int ve_printk_test_overflow(void)
> +{
> + int i;
> +
> + /*
> + * Ten program segfaults are enough to overflow the container's log buffer
> + * Run 15 to ensure the buffer is actually overflowed.
> + */
> + for (i = 0; i < 15; i++) {
> + system("./" SEGFAULT_PROG " > /dev/null");
> + /* bypass printk_ratelimit */
> + if (i == 9)
> + sleep(5);
> + }
> + return ve_printk_test_logct();
> +}
> +
> +int child_func(void *arg)
> +{
> + int ret;
> + int fd;
> + struct fargs *args = (struct fargs *)arg;
> + char cg_state[PATH_MAX];
> +
> + ret = setup_timens();
> + if (ret)
> + return ret;
> +
> + snprintf(cg_state, sizeof(cg_state), "%s/%d/ve.state", args->cgve, args->ctid);
> +
> + (void)umount2("/proc", MNT_DETACH);
> + ret = mount("proc", "/proc", "proc", 0, NULL);
> + if (ret < 0)
> + return ret;
> +
> + fd = open("/proc/self/uid_map", O_WRONLY);
> + if (fd < 0)
> + return -1;
> + write(fd, "0 0 1\n", 6);
ret/num of bytes check?
> + close(fd);
> +
> + fd = open("/proc/self/gid_map", O_WRONLY);
> + if (fd < 0)
> + return -1;
> + write(fd, "0 0 1\n", 6);
ret/num of bytes check?
> + close(fd);
> +
> + fd = open(cg_state, O_WRONLY);
> + if (fd < 0) {
> + return -1;
> + }
> +
> + if (write(fd, "START", strlen("START")) < 0) {
ret/num of bytes check?
> + close(fd);
> + return -1;
> + }
> +
> + close(fd);
> +
> + switch(args->test) {
> + case TEST_LOG:
> + ret = ve_printk_test_logct();
> + break;
> + case TEST_LOGV0:
> + ret = ve_printk_test_logve0();
> + break;
> + case TEST_LOGBOTH:
> + ret = ve_printk_test_logboth();
> + break;
> + case TEST_PR_RATELIMIT:
> + ret = ve_printk_test_ratelimit();
> + break;
> + case TEST_OVERFLOW:
> + ret = ve_printk_test_overflow();
> + break;
> + default:
> + ret = -1;
> + }
> + return ret;
> +}
> +
> +int enter_cgroup(const char *cgroup, int ctid)
> +{
> + char cg_path[PATH_MAX];
> + char pid_str[64];
> + int fd;
> + int ret = 0;
> +
> + if (ctid)
> + snprintf(cg_path, sizeof(cg_path), "%s/%d/cgroup.procs", cgroup, ctid);
> + else
> + snprintf(cg_path, sizeof(cg_path), "%s/cgroup.procs", cgroup);
> + snprintf(pid_str, sizeof(pid_str), "%d", getpid());
> + fd = open(cg_path, O_WRONLY);
> + if (fd < 0) {
> + return -1;
> + }
> +
> + if (write(fd, pid_str, strlen(pid_str)) < 0) {
There could be a partial write, need to check the amount of written bytes.
> + ret = -1;
> + }
> +
> + close(fd);
> + return ret;
> +}
> +
> +int run_vzct(char *cgv2, char *cgve, int ctid, int testid)
> +{
> + char *stack;
> + char *stack_top;
> + pid_t pid;
> + int flags = CLONE_NEWNS | CLONE_NEWUTS | CLONE_NEWIPC |
> + CLONE_NEWPID | CLONE_NEWUSER | CLONE_NEWNET |
> + CLONE_NEWCGROUP | SIGCHLD;
> + struct fargs args = {
> + .cgve = cgve,
> + .ctid = ctid,
> + .test = testid,
> + };
> + int status;
> + int ret;
> +
> + stack = malloc(__STACK_SIZE);
Missing free() for it?
> + if (!stack)
> + return -1;
> +
> + ret = enter_cgroup(cgv2, ctid);
> + if (ret < 0)
> + return -1;
> + ret = enter_cgroup(cgve, ctid);
> + if (ret < 0)
> + return -1;
> +
> + stack_top = stack + __STACK_SIZE;
> + pid = clone(child_func, stack_top, flags, &args);
> + if (pid < 0) {
> + return -1;
> + }
> +
> + ret = waitpid(pid, &status, 0);
> + if (ret < 0)
> + return -1;
> + ret = -1;
> + if (WIFEXITED(status)) {
> + ret = WEXITSTATUS(status);
> + }
> + enter_cgroup(cgv2, 0);
> + enter_cgroup(cgve, 0);
> +
> + return ret;
> +}
> +
> +FILE *open_dmesg(void)
> +{
> + int fd;
> + FILE *fdmesg;
> + char buf[1024];
> +
> + fd = open("/dev/kmsg", O_RDONLY | O_NONBLOCK);
> + if (fd < 0)
> + return NULL;
> + fdmesg = fdopen(fd, "r");
> + if (!fdmesg)
> + return NULL;
> +
> + while (fgets(buf, sizeof(buf), fdmesg)) ;
If fgets returns an error, "while" cycle will continue.
> + return fdmesg;
> +}
> +
> +int restore_param(const char *path, int val)
> +{
> + int fd;
> + char str[16];
> +
> + fd = open(path, O_WRONLY);
> + if (fd < 0)
> + return -1;
> + snprintf(str, sizeof(str), "%d", val);
> + write(fd, str, strlen(str));
To check the error code here?
> + close(fd);
> +
> + return 0;
> +}
> +
> +int set_param(const char *path, int val, int *old)
> +{
> + FILE *f;
> +
> + f = fopen(path, "r");
> + if (!f)
> + return -1;
> + if (fscanf(f, "%u", old) != 1) {
> + fclose(f);
> + return -1;
> + }
> + fclose(f);
> + if (*old == val)
> + return 0;
> + return restore_param(path, val);
> +}
> +
> +TEST_F(ve_printk, ve_log)
> +{
> + int ret;
> + FILE *fdmesg;
> + char buf[1024];
> + int old;
> +
> + ASSERT_EQ(set_param("/proc/sys/debug/exception-trace", 1, &old), 0);
> + fdmesg = open_dmesg();
> + ASSERT_NE(fdmesg, NULL);
> +
> + ret = run_vzct(self->cgv2_path, self->cgve_path, self->ctid, TEST_LOG);
> + ASSERT_EQ(ret, 0);
> +
> + while (fgets(buf, sizeof(buf), fdmesg)) {
> + ASSERT_EQ(strstr(buf, SEGFAULT_PROG) && strstr(buf, "segfault at"), false);
> + EXPECT_EQ(strstr(buf, "Code: "), NULL);
> + }
> + fclose(fdmesg);
> + restore_param("/proc/sys/debug/exception-trace", old);
> +}
> +
> +TEST_F(ve_printk, ve0_log)
> +{
> + int ret;
> + FILE *fdmesg;
> + char buf[1024];
> + int ex_trace;
> +
> + ASSERT_EQ(set_param("/proc/sys/debug/exception-trace", 1, &ex_trace), 0);
> + fdmesg = open_dmesg();
> + ASSERT_NE(fdmesg, NULL);
> +
> + ret = run_vzct(self->cgv2_path, self->cgve_path, self->ctid, TEST_LOGV0);
> + ASSERT_EQ(ret, 0);
> +
> + while (fgets(buf, sizeof(buf), fdmesg)) {
> + if (strstr(buf, "traps: test_trap[") &&
> + strstr(buf, " in test_trap[")) {
> + ret = 1;
> + break;
> + }
> + }
> + fclose(fdmesg);
> + restore_param("/proc/sys/debug/exception-trace", ex_trace);
> + ASSERT_EQ(ret, 1);
> +}
> +
> +TEST_F(ve_printk, ve_log_both)
> +{
> + int ret;
> + FILE *fdmesg;
> + char buf[1024];
> + int old_ratelimit;
> +
> + ASSERT_EQ(set_param("/proc/sys/net/core/message_burst",
> + TEST_RATELIMIT_BURST, &old_ratelimit), 0);
You change /proc/sys/net/core/message_burst
> + fdmesg = open_dmesg();
> + ASSERT_NE(fdmesg, NULL);
> +
> + ret = run_vzct(self->cgv2_path, self->cgve_path, self->ctid, TEST_LOGBOTH);
> + ASSERT_EQ(ret, 0);
> +
> + while (fgets(buf, sizeof(buf), fdmesg)) {
> + if (strstr(buf, "nf_conntrack table full, dropping packet")) {
> + ret++;
> + }
> + }
> + fclose(fdmesg);
> + restore_param("/proc/sys/kernel/printk_ratelimit_burst", old_ratelimit);
but restore /proc/sys/kernel/printk_ratelimit_burst ?
Should it be the same as above?
> + ASSERT_EQ(ret, TEST_RATELIMIT_BURST);
> +}
> +
> +TEST_F(ve_printk, ve_printk_ratelimited)
> +{
> + int ret;
> + FILE *fdmesg;
> + char buf[1024];
> + int old_ratelimit_burst;
> + int old_ratelimit;
> +
> + ASSERT_EQ(set_param("/proc/sys/net/core/message_burst",
> + TEST_RATELIMIT_BURST, &old_ratelimit_burst), 0);
You change /proc/sys/net/core/message_burst
> + ASSERT_EQ(set_param("/proc/sys/net/core/message_cost",
> + TEST_RATELIMIT, &old_ratelimit), 0);
> + fdmesg = open_dmesg();
> + ASSERT_NE(fdmesg, NULL);
> +
> + ret = run_vzct(self->cgv2_path, self->cgve_path, self->ctid, TEST_PR_RATELIMIT);
> + ASSERT_EQ(ret, 0);
> +
> + while (fgets(buf, sizeof(buf), fdmesg)) {
> + ASSERT_EQ(strstr(buf, "reject_tg_check") && strstr(buf, "callbacks suppressed"), false);
> + ASSERT_EQ(strstr(buf, "TCP_RESET invalid for non-tcp"), NULL);
> + }
> + fclose(fdmesg);
> + restore_param("/proc/sys/kernel/printk_ratelimit_burst", old_ratelimit_burst);
but restore /proc/sys/kernel/printk_ratelimit_burst ?
Should it be the same as above?
> + restore_param("/proc/sys/net/core/message_cost", old_ratelimit);
> +}
> +
> +TEST_F(ve_printk, ve_printk_overflow)
> +{
> + int ret;
> + int ex_trace;
> +
> + ASSERT_EQ(set_param("/proc/sys/debug/exception-trace", 1, &ex_trace), 0);
> +
> + ret = run_vzct(self->cgv2_path, self->cgve_path, self->ctid, TEST_OVERFLOW);
> + ASSERT_EQ(ret, 0);
> + restore_param("/proc/sys/debug/exception-trace", ex_trace);
> +
> +}
> +
> +TEST_HARNESS_MAIN
More information about the Devel
mailing list