Page MenuHomeFreeBSD
Files F174427529

D60186.id188268.diff
No OneTemporary
Actions

D60186.id188268.diff
View Options

diff --git a/sys/dev/hwpmc/hwpmc_logging.c b/sys/dev/hwpmc/hwpmc_logging.c
--- a/sys/dev/hwpmc/hwpmc_logging.c
+++ b/sys/dev/hwpmc/hwpmc_logging.c
@@ -66,6 +66,9 @@
#define curdomain PCPU_GET(domain)
+/* Max time to wait for the helper to write one buffer at close. */
+#define PMCLOG_DRAIN_STALL_MS 500
+
/*
* Sysctl tunables
*/
@@ -229,6 +232,8 @@
static void pmclog_loop(void *arg);
static void pmclog_release(struct pmc_owner *po);
static uint32_t *pmclog_reserve(struct pmc_owner *po, int length);
+static uint32_t *pmclog_reserve_flags(struct pmc_owner *po, int length,
+ bool closing);
static void pmclog_schedule_io(struct pmc_owner *po, int wakeup);
static void pmclog_schedule_all(struct pmc_owner *po);
static void pmclog_stop_kthread(struct pmc_owner *po);
@@ -410,8 +415,9 @@
for (;;) {
- /* check if we've been asked to exit */
- if ((po->po_flags & PMC_PO_OWNS_LOGFILE) == 0)
+ /* Exit if asked. After a close, write the queue first. */
+ if ((po->po_flags & PMC_PO_OWNS_LOGFILE) == 0 &&
+ (po->po_flags & PMC_PO_SHUTDOWN) == 0)
break;
if (lb == NULL) { /* look for a fresh buffer to write */
@@ -422,6 +428,8 @@
/* No more buffers and shutdown required. */
if (po->po_flags & PMC_PO_SHUTDOWN)
break;
+ if ((po->po_flags & PMC_PO_OWNS_LOGFILE) == 0)
+ break;
(void) msleep(po, &pmc_kthread_mtx, PWAIT,
"pmcloop", 250);
@@ -544,6 +552,13 @@
static uint32_t *
pmclog_reserve(struct pmc_owner *po, int length)
+{
+
+ return (pmclog_reserve_flags(po, length, false));
+}
+
+static uint32_t *
+pmclog_reserve_flags(struct pmc_owner *po, int length, bool closing)
{
uintptr_t newptr, oldptr __diagused;
struct pmclog_buffer *plb, **pplb;
@@ -554,7 +569,7 @@
("[pmclog,%d] length not a multiple of word size", __LINE__));
/* No more data when shutdown in progress. */
- if (po->po_flags & PMC_PO_SHUTDOWN)
+ if ((po->po_flags & PMC_PO_SHUTDOWN) != 0 && !closing)
return (NULL);
pplb = &po->po_curbuf[curcpu];
@@ -658,8 +673,39 @@
static void
pmclog_stop_kthread(struct pmc_owner *po)
{
+ TAILQ_HEAD(, pmclog_buffer) unwritten;
+ struct pmclog_buffer *head, *last;
+ TAILQ_INIT(&unwritten);
mtx_lock(&pmc_kthread_mtx);
+
+ /*
+ * After a close, let the helper write the queue. Stop waiting
+ * if it makes no progress, e.g. nobody reads a pipe.
+ */
+ mtx_lock_spin(&po->po_mtx);
+ last = TAILQ_FIRST(&po->po_logbuffers);
+ mtx_unlock_spin(&po->po_mtx);
+ while ((po->po_flags & PMC_PO_SHUTDOWN) != 0 &&
+ po->po_kthread != NULL) {
+ wakeup_one(po);
+ (void)msleep(po->po_kthread, &pmc_kthread_mtx, PPAUSE,
+ "pmckdrn", MAX(1, PMCLOG_DRAIN_STALL_MS * hz / 1000));
+ if (po->po_kthread == NULL)
+ break;
+ mtx_lock_spin(&po->po_mtx);
+ head = TAILQ_FIRST(&po->po_logbuffers);
+ mtx_unlock_spin(&po->po_mtx);
+ if (head == last)
+ break;
+ last = head;
+ }
+
+ /* Take the unwritten buffers; the caller frees them. */
+ mtx_lock_spin(&po->po_mtx);
+ TAILQ_CONCAT(&unwritten, &po->po_logbuffers, plb_next);
+ mtx_unlock_spin(&po->po_mtx);
+
po->po_flags &= ~PMC_PO_OWNS_LOGFILE;
if (po->po_kthread != NULL) {
PROC_LOCK(po->po_kthread);
@@ -670,6 +716,10 @@
while (po->po_kthread)
msleep(po->po_kthread, &pmc_kthread_mtx, PPAUSE, "pmckstp", 0);
mtx_unlock(&pmc_kthread_mtx);
+
+ mtx_lock_spin(&po->po_mtx);
+ TAILQ_CONCAT(&po->po_logbuffers, &unwritten, plb_next);
+ mtx_unlock_spin(&po->po_mtx);
}
/*
@@ -881,21 +931,32 @@
PMCDBG1(LOG,CLO,1, "po=%p", po);
- pmclog_process_closelog(po);
-
+ /*
+ * The close record must be the last record: a reader stops there.
+ * Hold pmc_kthread_mtx so the helper does not exit before it is
+ * queued.
+ */
mtx_lock(&pmc_kthread_mtx);
+
+ /* Already closed. */
+ if ((po->po_flags & PMC_PO_SHUTDOWN) != 0) {
+ mtx_unlock(&pmc_kthread_mtx);
+ return (0);
+ }
+
+ /* Log pending samples and queue the current buffers. */
+ pmclog_schedule_all(po);
+
/*
* Initiate shutdown: no new data queued,
* thread will close file on last block.
*/
po->po_flags |= PMC_PO_SHUTDOWN;
- /* give time for all to see */
- DELAY(50);
-
- /*
- * Schedule the current buffer.
- */
+
+ /* Queue records written before the other CPUs saw the flag. */
pmclog_schedule_all(po);
+
+ pmclog_process_closelog(po);
wakeup_one(po);
mtx_unlock(&pmc_kthread_mtx);
@@ -930,9 +991,22 @@
void
pmclog_process_closelog(struct pmc_owner *po)
{
- PMCLOG_RESERVE(po, PMCLOG_TYPE_CLOSELOG,
- sizeof(struct pmclog_closelog));
- PMCLOG_DESPATCH_SYNC(po);
+ struct pmclog_header *ph;
+ uint32_t *le;
+ int len;
+
+ /* PMC_PO_SHUTDOWN is already set; skip that check. */
+ len = sizeof(struct pmclog_closelog);
+ spinlock_enter();
+ if ((le = pmclog_reserve_flags(po, len, true)) == NULL) {
+ spinlock_exit();
+ return;
+ }
+ ph = (struct pmclog_header *)le;
+ ph->pl_header = _PMCLOG_TO_HEADER(PMCLOG_TYPE_CLOSELOG, len);
+ ph->pl_tsc = pmc_rdtsc();
+ pmclog_schedule_io(po, 1);
+ spinlock_exit();
}
void
diff --git a/tests/sys/pmc/pmc_log_test.c b/tests/sys/pmc/pmc_log_test.c
--- a/tests/sys/pmc/pmc_log_test.c
+++ b/tests/sys/pmc/pmc_log_test.c
@@ -49,13 +49,16 @@
*/
#include <sys/param.h>
+#include <sys/cpuset.h>
#include <sys/socket.h>
#include <sys/wait.h>
#include <errno.h>
#include <fcntl.h>
#include <pmc.h>
+#include <pmclog.h>
#include <signal.h>
+#include <stdbool.h>
#include <stdint.h>
#include <stdlib.h>
#include <string.h>
@@ -344,6 +347,120 @@
"close after the fd was closed in userland: %s", strerror(errno));
}
+/** @internal Pin the calling thread to one CPU; false if not possible. */
+static bool
+pin_to_cpu(int cpu)
+{
+ cpuset_t set;
+
+ CPU_ZERO(&set);
+ CPU_SET(cpu, &set);
+ return (cpuset_setaffinity(CPU_LEVEL_WHICH, CPU_WHICH_TID, -1,
+ sizeof(set), &set) == 0);
+}
+
+/** @internal Return two CPUs this process may run on, or skip. */
+static void
+require_two_cpus(int *first, int *second)
+{
+ cpuset_t set;
+ int cpu, n;
+
+ ATF_REQUIRE(cpuset_getaffinity(CPU_LEVEL_WHICH, CPU_WHICH_PID, -1,
+ sizeof(set), &set) == 0);
+ n = 0;
+ for (cpu = 0; cpu < CPU_SETSIZE && n < 2; cpu++) {
+ if (!CPU_ISSET(cpu, &set))
+ continue;
+ if (n++ == 0)
+ *first = cpu;
+ else
+ *second = cpu;
+ }
+ if (n < 2)
+ atf_tc_skip("needs two CPUs");
+}
+
+#define CLOSE_ORDER_RECORDS 64
+#define CLOSE_ORDER_MARKER 0x434c4f00U
+
+/**
+ * @internal
+ * Write records on one CPU and close the log on another. All records
+ * must come before the close record, where a reader stops.
+ */
+ATF_TC_WITHOUT_HEAD(close_record_is_last);
+ATF_TC_BODY(close_record_is_last, tc)
+{
+ struct pmclog_ev ev;
+ char *buf;
+ void *parser;
+ off_t len;
+ size_t off;
+ uint32_t h;
+ int closes, cpu_close, cpu_write, fd, i, seen, stray;
+
+ require_hwpmc();
+ require_two_cpus(&cpu_close, &cpu_write);
+ fd = work_file("close-order.pmclog");
+ ATF_REQUIRE_MSG(pmc_configure_logfile(fd) == 0,
+ "pmc_configure_logfile: %s", strerror(errno));
+
+ ATF_REQUIRE_MSG(pin_to_cpu(cpu_write), "cannot pin to CPU %d: %s",
+ cpu_write, strerror(errno));
+ for (i = 0; i < CLOSE_ORDER_RECORDS; i++)
+ ATF_REQUIRE_MSG(pmc_writelog(CLOSE_ORDER_MARKER | i) == 0,
+ "pmc_writelog: %s", strerror(errno));
+
+ ATF_REQUIRE_MSG(pin_to_cpu(cpu_close), "cannot pin to CPU %d: %s",
+ cpu_close, strerror(errno));
+ ATF_REQUIRE_MSG(pmc_close_logfile() == 0, "pmc_close_logfile: %s",
+ strerror(errno));
+ ATF_REQUIRE_MSG(pmc_configure_logfile(-1) == 0,
+ "pmc_configure_logfile(-1): %s", strerror(errno));
+
+ ATF_REQUIRE(lseek(fd, 0, SEEK_SET) == 0);
+ ATF_REQUIRE((parser = pmclog_open(fd)) != NULL);
+ seen = 0;
+ while (pmclog_read(parser, &ev) == 0) {
+ if (ev.pl_type == PMCLOG_TYPE_USERDATA &&
+ (ev.pl_u.pl_u.pl_userdata & ~0xffU) == CLOSE_ORDER_MARKER)
+ seen++;
+ }
+ ATF_CHECK_MSG(ev.pl_state == PMCLOG_EOF,
+ "log parse ended in state %d", ev.pl_state);
+ pmclog_close(parser);
+
+ /* The parser stops at the close record; scan the raw file. */
+ closes = stray = 0;
+ ATF_REQUIRE((len = lseek(fd, 0, SEEK_END)) > 0);
+ ATF_REQUIRE((buf = malloc(len)) != NULL);
+ ATF_REQUIRE(pread(fd, buf, len, 0) == len);
+ for (off = 0; off + sizeof(h) <= (size_t)len;
+ off += PMCLOG_HEADER_TO_LENGTH(h)) {
+ memcpy(&h, buf + off, sizeof(h));
+ if (!PMCLOG_HEADER_CHECK_MAGIC(h) ||
+ PMCLOG_HEADER_TO_LENGTH(h) < sizeof(h)) {
+ atf_tc_fail("bad log record header 0x%08x at offset %zu",
+ h, off);
+ }
+ if (PMCLOG_HEADER_TO_TYPE(h) == PMCLOG_TYPE_CLOSELOG)
+ closes++;
+ else if (closes > 0)
+ stray++;
+ }
+ free(buf);
+ (void)close(fd);
+
+ ATF_CHECK_MSG(closes == 1, "%d close records in the log", closes);
+
+ ATF_CHECK_MSG(seen == CLOSE_ORDER_RECORDS,
+ "a reader saw %d of %d records written before the close",
+ seen, CLOSE_ORDER_RECORDS);
+ ATF_CHECK_MSG(stray == 0, "%d records follow the close record",
+ stray);
+}
+
/**
* @internal
* A write error on the log has to reach userland rather than be swallowed.
@@ -447,6 +564,7 @@
ATF_TP_ADD_TC(tp, log_ops_without_an_owner);
ATF_TP_ADD_TC(tp, log_survives_userland_closing_the_fd);
ATF_TP_ADD_TC(tp, log_write_error_is_reported);
+ ATF_TP_ADD_TC(tp, close_record_is_last);
ATF_TP_ADD_TC(tp, owner_exit_with_log_and_running_pmc);
return (atf_no_error());

File Metadata

Mime Type
text/plain
Expires
Sun, Oct 4, 3:19 AM (5 h, 29 m)
Storage Engine
blob
Storage Format
Raw Data
Storage Handle
40052057
Default Alt Text
D60186.id188268.diff (9 KB)

Event Timeline