3311 Want a test framework for arbitrary OS unit tests

[illumos-gate.git] / usr / src / test / os-tests / tests / poll / poll_test.c

/*
 * This file and its contents are supplied under the terms of the
 * Common Development and Distribution License ("CDDL"), version 1.0.
 * You may only use this file in accordance with the terms of version
 * 1.0 of the CDDL.
 *
 * A full copy of the text of the CDDL should have accompanied this
 * source.  A copy of the CDDL is also available via the Internet at
 * http://www.illumos.org/license/CDDL.
 */

/*
 * Copyright (c) 2012 by Delphix. All rights reserved.
 */

#include <stdlib.h>
#include <stdio.h>
#include <stdarg.h>
#include <string.h>
#include <fcntl.h>
#include <pthread.h>
#include <assert.h>
#include <errno.h>
#include <ctype.h>
#include <unistd.h>
#include <poll.h>
#include <sys/types.h>
#include <sys/wait.h>
#include <sys/stat.h>
#include <sys/socket.h>
#include <sys/devpoll.h>

/*
 * poll_test.c --
 *
 *      This file implements some simple tests to verify the behavior of the
 *      poll system call and the DP_POLL ioctl on /dev/poll.
 *
 * Background:
 *
 *      Several customers recently ran into an issue where threads in grizzly
 *      (java http server implementation) would randomly wake up from a java
 *      call to select against a java.nio.channels.Selector with no events ready
 *      but well before the specified timeout expired. The
 *      java.nio.channels.Selector select logic is implemented via /dev/poll.
 *      The selector opens /dev/poll, writes the file descriptors it wants to
 *      select on to the file descritpor, and then issues a DP_POLL ioctl to
 *      wait for events to be ready.
 *
 *      The DP_POLL ioctl arguments include a relative timeout in milliseconds,
 *      according to man poll.7d the ioctl should block until events are ready,
 *      the timeout expires, or a signal was received. In this case we noticed
 *      that DP_POLL was returning before the timeout expired despite no events
 *      being ready and no signal being delivered.
 *
 *      Using dtrace we discovered that DP_POLL was returning in cases where the
 *      system time was changed and the thread calling DP_POLL was woken up as
 *      a result of the process forking. The DP_POLL logic was in a loop
 *      checking if events were ready and then calling cv_waituntil_sig to
 *      block. cv_waituntil_sig will return -1 if the system time has changed,
 *      causing the DP_POLL to complete prematurely.
 *
 *      Looking at the code it turns out the same problem exists in
 *      the implementation for poll.2 as well.
 *
 * Fix:
 *
 *      The fix changes dpioctl and poll_common to use cv_relwaituntil_sig
 *      rather then cv_waituntil_sig. cv_reltimedwait_sig expects a
 *      relative timeout rather then an absolute timeout, so we avoid the
 *      problem.
 *
 * Test:
 *
 *      The test verifies that changing the date does not wake up threads
 *      blocked processing a poll request or a DP_POLL ioctl. The test spawns
 *      one thread that changes the date and forks (to force the threads to
 *      wakeup from cv_reltimedwait_sig) every two seconds. The test spawns
 *      a second thread that issues poll / DP_POLL on an fd set that will
 *      never have events ready and verifies that it does not return until
 *      the specified timeout expires.
 */

/*
 * The maximum amount of skew in seconds allowed between the
 * expected an actual time that a test takes.
 */
#define TIME_DRIFT      1

static pthread_mutex_t  exitLock = PTHREAD_MUTEX_INITIALIZER;
static pthread_cond_t   exitCond = PTHREAD_COND_INITIALIZER;
static int              terminated = 0;

/*
 * Set via -d to enable debug logging
 */
static int debug = 0;

static void
debug_log(const char *format, ...)
{
        va_list args;

        if (!debug) {
                return;
        }

        (void) printf("DEBUG: ");

        va_start(args, format);
        (void) vprintf(format, args);
        va_end(args);
}

static void
test_start(const char *testName, const char *format, ...)
{
        va_list args;

        (void) printf("TEST STARTING %s: ", testName);

        va_start(args, format);
        (void) vprintf(format, args);
        va_end(args);
        (void) fflush(stdout);
}

static void
test_failed(const char *testName, const char *format, ...)
{
        va_list args;

        (void) printf("TEST FAILED %s: ", testName);

        va_start(args, format);
        (void) vprintf(format, args);
        va_end(args);

        (void) exit(-1);
}

static void
test_passed(const char *testName)
{
        (void) printf("TEST PASS: %s\n", testName);
        (void) fflush(stdout);
}

static int
check_time(time_t elapsed, time_t expected)
{
        time_t  diff = expected - elapsed;

        /*
         * We may take slightly more or less time then expected,
         * we allow for a small fudge factor if things completed
         * before we expect them to.
         */
        return (elapsed >= expected || diff <= TIME_DRIFT);
}

static int
poll_wrapper(pollfd_t *fds, nfds_t nfds, int timeout, time_t *elapsed)
{
        int             ret;
        time_t          start = time(NULL);

        debug_log("POLL start: (0x%p, %d, %d)\n", fds, nfds, timeout);

        ret = poll(fds, nfds, timeout);

        *elapsed = time(NULL) - start;

        debug_log("POLL end: (0x%p, %d, %d) returns %d (elapse=%d)\n",
            fds, nfds, timeout, ret, (*elapsed));

        return (ret);
}

static int
dppoll(int pollfd, pollfd_t *fds, nfds_t nfds, int timeout, time_t *elapsed)
{
        struct dvpoll   arg;
        int             ret;
        time_t          start = time(NULL);

        arg.dp_fds = fds;
        arg.dp_nfds = nfds;
        arg.dp_timeout = timeout;

        debug_log("DP_POLL start: (0x%p, %d, %d)\n", fds, nfds, timeout);

        ret = ioctl(pollfd, DP_POLL, &arg);

        *elapsed = time(NULL) - start;

        debug_log("DP_POLL end: (0x%p, %d, %d) returns %d (elapse=%d)\n",
            fds, arg.dp_nfds, arg.dp_timeout, ret, (*elapsed));

        return (ret);
}

static void
clear_fd(const char *testName, int pollfd, int testfd)
{
        int             ret;
        pollfd_t        fd;

        fd.fd = testfd;
        fd.events = POLLREMOVE;
        fd.revents = 0;

        ret = write(pollfd, &fd, sizeof (pollfd_t));

        if (ret != sizeof (pollfd_t)) {
                if (ret < 0) {
                        test_failed(testName, "Failed to clear fd %d: %s",
                            testfd, strerror(ret));
                }


                test_failed(testName, "Failed to clear fd %d: %d", testfd, ret);
        }
}

/*
 * TEST: poll with no FDs set, verify we wait the appropriate amount of time.
 */
static void
poll_no_fd_test(void)
{
        const char      *testName = __func__;
        time_t          elapsed;
        int             timeout = 10;
        int             ret;

        test_start(testName, "poll for %d sec with no fds\n", timeout);

        ret = poll_wrapper(NULL, 0, timeout * 1000, &elapsed);

        if (ret != 0) {
                test_failed(testName, "POLL returns %d (expected 0)\n", ret);
        }

        if (!check_time(elapsed, timeout)) {
                test_failed(testName, "took %d (expected %d)\n",
                    elapsed, timeout);
        }

        test_passed(testName);
}

/*
 * TEST: POLL with a valid FD set, verify that we wait the appropriate amount
 * of time.
 */
static void
poll_with_fds_test(int testfd)
{
        const char      *testName = __func__;
        time_t          elapsed;
        int             timeout = 10;
        int             ret;
        pollfd_t        fd;

        fd.fd = testfd;
        fd.events = 0;
        fd.revents = 0;

        test_start(testName, "poll for %d sec with fds\n", timeout);

        ret = poll_wrapper(&fd, 1, timeout * 1000, &elapsed);

        if (ret != 0) {
                test_failed(testName, "POLL returns %d (expected 0)\n", ret);
        }

        if (!check_time(elapsed, timeout)) {
                test_failed(testName, "took %d (expected %d)\n",
                    elapsed, timeout);
        }

        test_passed(testName);
}

/*
 * TEST: DP_POLL with no FDs set, verify we wait the appropriate
 * amount of time.
 */
static void
dev_poll_no_fd_test(int pollfd)
{
        const char      *testName = __func__;
        time_t          elapsed;
        int             timeout = 10;
        int             ret;

        test_start(testName, "poll for %d sec with no fds\n", timeout);

        ret = dppoll(pollfd, NULL, 0, timeout * 1000, &elapsed);

        if (ret != 0) {
                test_failed(testName, "DP_POLL returns %d (expected 0)\n", ret);
        }

        if (!check_time(elapsed, timeout)) {
                test_failed(testName, "took %d (expected %d)\n",
                    elapsed, timeout);
        }

        test_passed(testName);
}

/*
 * TEST: DP_POLL with a valid FD set, verify that we wait
 * the appropriate amount of time.
 */
static void
dev_poll_with_fds_test(int pollfd, int testfd)
{
        const char      *testName = __func__;
        time_t          elapsed;
        int             timeout = 10;
        int             ret;
        pollfd_t        fds[5];

        test_start(testName, "poll for %d sec with fds\n", timeout);

        /*
         * Clear the FD in case it's already in the cached set
         */
        clear_fd(testName, pollfd, testfd);

        /*
         * Add the FD with POLLIN
         */
        fds[0].fd = testfd;
        fds[0].events = POLLIN;
        fds[0].revents = 0;

        ret = write(pollfd, fds, sizeof (pollfd_t));

        if (ret != sizeof (pollfd_t)) {
                if (ret < 0) {
                        test_failed(testName, "Failed to set fds: %s",
                            strerror(ret));
                }

                test_failed(testName, "Failed to set fds: %d", ret);
        }

        ret = dppoll(pollfd, fds, 5, timeout * 1000, &elapsed);

        if (ret != 0) {
                test_failed(testName, "DP_POLL returns %d (expected 0)\n", ret);
        }

        if (!check_time(elapsed, timeout)) {
                test_failed(testName, "took %d (expected %d)\n",
                    elapsed, timeout);
        }

        clear_fd(testName, pollfd, testfd);

        test_passed(testName);
}

/* ARGSUSED */
static void *
poll_thread(void *data)
{
        int     pollfd;
        int     testfd;

        pollfd = open("/dev/poll", O_RDWR);

        if (pollfd <  0) {
                perror("Failed to open /dev/poll: ");
                exit(-1);
        }

        /*
         * Create a dummy FD that will never have POLLIN set
         */
        testfd = socket(PF_INET, SOCK_STREAM, 0);

        poll_no_fd_test();
        poll_with_fds_test(testfd);

        dev_poll_no_fd_test(pollfd);
        dev_poll_with_fds_test(pollfd, testfd);

        (void) close(testfd);
        (void) close(pollfd);

        pthread_exit(0);
        return (NULL);
}

/*
 * This function causes any threads blocked in cv_timedwait_sig_hires
 * to wakeup, which allows us to test how dpioctl handles spurious
 * wakeups.
 */
static void
trigger_wakeup(void)
{
        pid_t   child;

        /*
         * Forking will force all of the threads to be woken up so
         * they can be moved to a well known state.
         */
        child = vfork();

        if (child == -1) {
                perror("Fork failed: ");
                exit(-1);
        } else if (child == 0) {
                _exit(0);
        } else {
                pid_t   result = -1;
                int     status;

                do {
                        result = waitpid(child, &status, 0);

                        if (result == -1 && errno != EINTR) {
                                (void) printf("Waitpid for %ld failed: %s\n",
                                    child, strerror(errno));
                                exit(-1);
                        }
                } while (result != child);

                if (status != 0) {
                        (void) printf("Child pid %ld failed: %d\n",
                            child, status);
                        exit(-1);
                }
        }
}

/*
 * This function changes the system time, which has the side
 * effect of updating timechanged in the kernel.
 */
static void
change_date(void)
{
        int     ret;
        struct timeval  tp;

        ret = gettimeofday(&tp, NULL);
        assert(ret == 0);

        tp.tv_usec++;
        ret = settimeofday(&tp, NULL);
        assert(ret == 0);
}

/*
 * The helper thread runs in a loop changing the time and
 * forcing wakeups every 2 seconds.
 */
/* ARGSUSED */
static void *
helper_thread(void *data)
{
        int     exit;
        struct  timespec ts = {2, 0};

        debug_log("Helper thread started ...\n");

        /* CONSTCOND */
        while (1) {
                (void) pthread_mutex_lock(&exitLock);
                (void) pthread_cond_reltimedwait_np(&exitCond, &exitLock, &ts);
                exit = terminated;
                (void) pthread_mutex_unlock(&exitLock);

                if (exit) {
                        break;
                }

                change_date();
                trigger_wakeup();
                debug_log("Time changed and force wakeup issued\n");
        }

        debug_log("Helper thread exiting ...\n");

        pthread_exit(0);
        return (NULL);
}

static void
stop_threads(void)
{
        (void) pthread_mutex_lock(&exitLock);
        terminated = 1;
        (void) pthread_cond_broadcast(&exitCond);
        (void) pthread_mutex_unlock(&exitLock);
}

static void
run_tests(void)
{
        pthread_t       pollThread;
        pthread_t       helperThread;
        int             ret;

        ret = pthread_create(&helperThread, NULL, helper_thread, NULL);

        if (ret != 0) {
                (void) printf("Failed to create date thread: %s",
                    strerror(ret));
                exit(-1);
        }

        ret = pthread_create(&pollThread, NULL, poll_thread, NULL);

        if (ret != 0) {
                (void) printf("Failed to create poll thread: %s",
                    strerror(ret));
                exit(-1);
        }

        (void) pthread_join(pollThread, NULL);
        stop_threads();
        (void) pthread_join(helperThread, NULL);
}

int
main(int argc, char * const argv[])
{
        int     c;

        while ((c = getopt(argc, argv, "d")) != -1) {
                switch (c) {
                case 'd':
                        debug = 1;
                        break;
                default:
                        break;
                }
        }

        /*
         * We need to be root to change the system time
         */
        if (getuid() != 0 && geteuid() != 0) {
                (void) printf("%s must be run as root\n", argv[0]);
                exit(-1);
        }

        run_tests();

        exit(0);
}