Re: [Devel] [PATCH vz10 v2 2/2] selftests: ve: introduce vtty pair teardown stress test

[Konstantin Khorenko <khorenko@virtuozzo.com>]

> A vtty pair is created by the first master open and torn down by the
> last close. The close racing the peer's close used to let both sides
> decide they were the final one and call release_tty() twice, and a
> master opening again while a teardown was in flight used to hand out a
> reference to a tty_struct about to be freed.
> 
> Hammer both ends. The master comes from the vzctl ioctl, which does
> not look the VE up. The slave is only reachable from inside the VE, as
> TTY_MAJOR minor 1..MAX_NR_VTTY_CONSOLES, which vtty_driver() maps to
> vttys index minor - 1, so the test builds a VE with cgroup2, sets
> ve.veid to the cgroup it made, and runs the slave side there.
> 
> One of the symtoms of a buggy kernel is dmesg warning, not just an
> eventual crash, so the test checks that. A crashed node should also
> report test failure in CI, but that's less verbose, hence the check.

Typo: symtoms. The second sentence argues against itself ("should also
report ... hence the check"). One sentence carries the point: a warning
does not stop the node, so the test reads the kernel log.

> 
> https://virtuozzo.atlassian.net/browse/VSTOR-144771
> 
> Feature: ve selftest
> Signed-off-by: Eva Kurchatova <eva.kurchatova@virtuozzo.com>
>
> diff --git a/tools/testing/selftests/ve/.gitignore b/tools/testing/selftests/ve/.gitignore
> index afa4c568c2c9b..9d8d860938273 100644
> --- a/tools/testing/selftests/ve/.gitignore
> +++ b/tools/testing/selftests/ve/.gitignore
> @@ -1,2 +1,3 @@
>  ve_ns_owner_test
>  ve_perms_test
> +ve_vtty_stress
> diff --git a/tools/testing/selftests/ve/Makefile b/tools/testing/selftests/ve/Makefile
> index ec40cbc7b3a1b..6cd5823c4d932 100644
> --- a/tools/testing/selftests/ve/Makefile
> +++ b/tools/testing/selftests/ve/Makefile
> @@ -4,5 +4,6 @@ CFLAGS += -g -Wall -O2
>  
>  TEST_GEN_PROGS += ve_ns_owner_test
>  TEST_GEN_PROGS += ve_perms_test
> +TEST_GEN_PROGS += ve_vtty_stress
>  
>  include ../lib.mk
> diff --git a/tools/testing/selftests/ve/settings b/tools/testing/selftests/ve/settings
> new file mode 100644
> index 0000000000000..e2206265f67c7
> --- /dev/null
> +++ b/tools/testing/selftests/ve/settings
> @@ -0,0 +1 @@
> +timeout=900
> diff --git a/tools/testing/selftests/ve/ve_vtty_stress.c b/tools/testing/selftests/ve/ve_vtty_stress.c
> new file mode 100644
> index 0000000000000..57edbdeef0c84
> --- /dev/null
> +++ b/tools/testing/selftests/ve/ve_vtty_stress.c
> @@ -0,0 +1,250 @@
> +// SPDX-License-Identifier: GPL-2.0
> +/*
> + * ve_vtty_stress - close a vtty pair from both ends at once.
> + *
> + * A vtty pair is created by the first master open and torn down by the
> + * last close. A close racing the peer's close used to let both sides
> + * decide they were the final one and call release_tty() twice, and a
> + * master opened again while a teardown was still in flight used to hand
> + * out a reference to a tty_struct that was about to be freed. Either
> + * way the next close walked freed memory.
> + *
> + * The master comes from the vzctl ioctl, which does not look the VE up.
> + * The slave is only reachable from inside the VE, as TTY_MAJOR minor
> + * 1..MAX_NR_VTTY_CONSOLES, which vtty_driver() maps to vttys index
> + * minor - 1. So the test makes a VE with cgroup2, hammers the master
> + * from the host and the slave from a task inside it, and fails if the
> + * kernel logs a complaint about the teardown.
> + *
> + * Surviving is not a pass on its own: the first symptom is a warning,
> + * which stops nothing by itself.

This is the commit message pasted into the file. The history of the
double release_tty() and the freed tty_struct belongs in the commit,
where git keeps it next to the change. The header needs what the test
does, how it reaches both ends, and the usage line. Also, "created by the
first master open" is not the whole story: the slave open creates the
pair too, since vtty_lookup() returns NULL for a missing map and
tty_init_dev(vttys_driver) then runs vtty_install(). In this test the
slave wins that race often.

> + *
> + * Usage: ve_vtty_stress [seconds] (default 600, or $VE_VTTY_SECS)
> + */
> +#define _GNU_SOURCE
> +#include <sched.h>
> +#include <stdbool.h>
> +#include <sys/ioctl.h>
> +#include <linux/major.h>
> +#include <sys/sysmacros.h>
> +#include <sys/wait.h>
> +#include <time.h>
> +
> +#include "ve_selftest.h"
> +#include "../kselftest.h"
> +
> +/* The ioctl argument; the trailing data[] the uapi struct has is unused. */
> +struct vzctl_ve_configure {
> +	unsigned int veid, key, val, size;
> +};
> +
> +#define VZCTL_VE_CONFIGURE _IOW('.', 15, struct vzctl_ve_configure)
> +#define VE_CONFIGURE_OPEN_TTY 5
> +
> +#define VTTY_IDX 0 /* the pair both ends work on */
> +#define SLAVE_MINOR (VTTY_IDX + 1) /* vtty_driver(): index = minor - 1 */
> +#define DEFAULT_SECS 600

ve_vtty_stress is in TEST_GEN_PROGS, so every "make run_tests" of the ve
directory now takes ten minutes longer, and the settings file lifts the
timeout for the whole directory to make room for that. Nothing in the
commit says how long the original bug took to show up. If it reproduced
in seconds, a default in the tens of seconds keeps the test in the
default run and the long soak stays available through VE_VTTY_SECS or
argv[1]. If it really needs minutes, that deserves a sentence in the
commit message.

> +
> +static int open_master(int ctl_fd, unsigned int veid)
> +{
> +	struct vzctl_ve_configure c = {
> +		.veid = veid,
> +		.key = VE_CONFIGURE_OPEN_TTY,
> +		.val = VTTY_IDX,
> +	};
> +
> +	return ioctl(ctl_fd, VZCTL_VE_CONFIGURE, &c);
> +}
> +
> +/*
> + * The slave end, inside the VE. Every error here is one the race is
> + * expected to produce: the pair is gone once the master has closed it.
> + */
> +static int hammer_slave(time_t deadline, unsigned long *opened)
> +{
> +	char node[] = "/tmp/ve_vtty_slave";

A fixed name under /tmp is not that good.
A name with the pid in it, or a node under a private directory, could be better.

> +
> +	unlink(node);
> +	if (mknod(node, S_IFCHR | 0600, makedev(TTY_MAJOR, SLAVE_MINOR)) < 0)
> +		return -1;
> +
> +	while (time(NULL) < deadline) {
> +		int fd = open(node, O_RDWR | O_NOCTTY | O_NONBLOCK);
> +
> +		if (fd >= 0) {
> +			(*opened)++;
> +			close(fd);
> +		}
> +	}

The comment is not true for EPERM, EACCES, ENOENT or ENODEV: none of
those comes from the race, all of them mean the slave cannot be opened
at all (a /tmp mounted nodev gives EACCES from may_open(), for one). The
loop ignores errno, so a broken setup spins for the full run and only
then fails with "no slave was ever opened". Bail out on the first errno
that is not EBUSY/EIO/ENXIO and report it. The master loop has the same
shape and the same fix.

> +	unlink(node);
> +	return 0;
> +}
> +
> +/* The kernel log, since a warning fails nothing by itself. */
> +static int kmsg_open(void)
> +{
> +	int fd = open("/dev/kmsg", O_RDONLY | O_NONBLOCK);
> +
> +	if (fd >= 0)
> +		lseek(fd, 0, SEEK_END);
> +	return fd;
> +}
> +
> +static int kmsg_check(int fd)
> +{
> +	static const char *const ours[] = {
> +		"tty_release",	    "release_tty",   "check_tty_count",
> +		"vtty_open_master", "vtty_shutdown",
> +	};
> +	char buf[8192];
> +	int found = 0;
> +	ssize_t r;
> +	size_t i;
> +
> +	while (fd >= 0 && (r = read(fd, buf, sizeof(buf) - 1)) > 0) {
> +		buf[r] = '\0';
> +		if (!strstr(buf, "WARNING") && !strstr(buf, "BUG") &&
> +		    !strstr(buf, "Oops") && !strstr(buf, "general protection"))
> +			continue;
> +		for (i = 0; i < ARRAY_SIZE(ours); i++)
> +			if (strstr(buf, ours[i])) {
> +				ksft_print_msg("kernel log: %s", buf);
> +				found++;
> +				break;
> +			}
> +	}
> +	return found;
> +}

/dev/kmsg returns one record per read(), and the keyword and the
function name have to be in the same record for this to match. They
rarely are:

  - "WARNING: CPU: 0 PID: 1 at drivers/tty/pty.c:NNN vtty_map_clear+0x.."
    names vtty_map_clear(), the function holding the WARN_ON(). It
    matches vtty_shutdown only if the compiler inlined the static helper.
    The WARN_ON()s in vtty_map_set() and vtty_lookup() never match.
  - "Oops: 0000 [#1] ..." and "general protection fault, ..." carry no
    function name at all; that is in the RIP: record that follows.
  - "BUG: KASAN: slab-use-after-free in tty_lock+0x.." or a
    "list_del corruption" splat name none of the five.
  - check_tty_count() prints
    "vtty_slave vttys0: tty_release: tty->count(N) != (#fd's(M) + ..."
    with no WARNING/BUG/Oops in it, so the first strstr() chain skips the
    record before the names are tried, and the entry cannot match.

The test can therefore pass on the kernel it is meant to catch. The node
does nothing else during the run, so any WARNING/BUG/Oops/GPF record is a
failure; drop the function filter, and add the "tty->count(" text as a
match of its own.

One more thing here:
The read loop ends on the first error, and /dev/kmsg returns -EPIPE once
when the reader's position has been overwritten (devkmsg_read(), "our
last seen message is gone, return error and reset"), then continues from
the oldest record. Nothing drains the log during the run, so a buggy
kernel that WARNs on every double teardown for ten minutes overruns the
ring, the first read() after the deadline fails with EPIPE, kmsg_check()
returns 0 and the test passes. Skip EPIPE with a continue, or drain the
fd from the main loop.

> +
> +int main(int argc, char **argv)
> +{
> +	unsigned long master_opened = 0, slave_opened = 0;
> +	int cg, ctid, ctl, kmsg, ready[2], count[2], status;
> +	const char *env = getenv("VE_VTTY_SECS");
> +	char path[PATH_MAX], val[16], c;
> +	time_t deadline;
> +	long secs;
> +	pid_t pid;
> +
> +	ksft_print_header();
> +	secs = argc > 1 ? atol(argv[1]) : (env ? atol(env) : DEFAULT_SECS);
> +	if (secs <= 0)
> +		secs = DEFAULT_SECS;
> +
> +	ctl = open("/dev/vzctl", O_RDWR);
> +	if (ctl < 0)
> +		ksft_exit_skip("cannot open /dev/vzctl: %s, the vz modules "
> +			       "(vzdev, vzmon) are needed\n",
> +			       strerror(errno));
> +
> +	cg = mount_cg2_fd();
> +	if (cg < 0)
> +		ksft_exit_skip("cannot mount cgroup2: %s\n", strerror(errno));
> +	write_file_at(cg, "cgroup.subtree_control", VE_CONTROLLERS);
> +
> +	ctid = make_ve(cg, CTID_MIN);
> +	if (ctid < 0)
> +		ksft_exit_skip("cannot make a VE cgroup\n");
> +
> +	/*
> +	 * The pair is filed under the veid of the VE, so the two ends only
> +	 * meet if the cgroup carries the one the master is opened for.
> +	 */
> +	snprintf(path, sizeof(path), "%d/ve.veid", ctid);
> +	snprintf(val, sizeof(val), "%d", ctid);

ve_id_write() does not check that a veid is unique (the FIXME in
kernel/ve/ve.c says as much), and the vtty map is a global idr keyed by
veid. make_ve() only guarantees that no cgroup of that name exists in the
hierarchy, not that no running container carries that veid. The
108..200 range makes a clash unlikely on a test node; a sentence in the
commit message saying the test assumes it is enough.

> +	if (write_file_at(cg, path, val) < 0) {
> +		destroy_ve(cg, ctid);
> +		ksft_exit_skip("cannot set ve.veid: %s\n", strerror(errno));
> +	}
> +
> +	/* Do not report a failure where the vtty pair cannot be had at all. */
> +	status = open_master(ctl, ctid);
> +	if (status < 0 && errno != EBUSY) {
> +		destroy_ve(cg, ctid);
> +		ksft_exit_skip("no vtty master: %s\n", strerror(errno));
> +	}
> +	if (status >= 0)
> +		close(status);
> +
> +	ksft_set_plan(1);
> +	kmsg = kmsg_open();
> +	if (kmsg < 0)
> +		ksft_print_msg("cannot read /dev/kmsg: %s, only a crash will "
> +			       "be noticed\n",
> +			       strerror(errno));
> +
> +	if (pipe(ready) || pipe(count))
> +		ksft_exit_fail_msg("pipe: %s\n", strerror(errno));

Every other exit after make_ve() calls destroy_ve() first; this one
leaves the cgroup behind.

-- 
Konstantin Khorenko <khorenko@virtuozzo.com>
_______________________________________________
Devel mailing list
Devel@openvz.org
https://lists.openvz.org/mailman/listinfo/devel