From: Darrick J. Wong <djwong@xxxxxxxxxx>
XFS has a rather slow reflink operation. While a reflink operation is
running, other programs cannot read the contents of the source file,
which is causing latency spikes. Catherine Hoang wrote a patch to
permit reads, since the source file contents do not change. This is a
functionality test for that patch.
Signed-off-by: Darrick J. Wong <djwong@xxxxxxxxxx>
---
src/Makefile | 2
src/t_reflink_read_race.c | 343 +++++++++++++++++++++++++++++++++++++++++++++
tests/generic/1953 | 74 ++++++++++
tests/generic/1953.out | 6 +
4 files changed, 424 insertions(+), 1 deletion(-)
create mode 100644 src/t_reflink_read_race.c
create mode 100755 tests/generic/1953
create mode 100644 tests/generic/1953.out
diff --git a/src/Makefile b/src/Makefile
index 72c8a13007..b5e2b84dae 100644
--- a/src/Makefile
+++ b/src/Makefile
@@ -33,7 +33,7 @@ LINUX_TARGETS = xfsctl bstat t_mtab getdevicesize preallo_rw_pattern_reader \
attr_replace_test swapon mkswap t_attr_corruption t_open_tmpfiles \
fscrypt-crypt-util bulkstat_null_ocount splice-test chprojid_fail \
detached_mounts_propagation ext4_resize t_readdir_3 splice2pipe \
- uuid_ioctl usemem_and_swapoff
+ uuid_ioctl usemem_and_swapoff t_reflink_read_race
EXTRA_EXECS = dmerror fill2attr fill2fs fill2fs_check scaleread.sh \
btrfs_crc32c_forged_name.py popdir.pl popattr.py \
diff --git a/src/t_reflink_read_race.c b/src/t_reflink_read_race.c
new file mode 100644
index 0000000000..acf8f8f73c
--- /dev/null
+++ b/src/t_reflink_read_race.c
@@ -0,0 +1,343 @@
+// SPDX-License-Identifier: GPL-2.0
+/*
+ * Race reads with reflink to see if reads continue while we're cloning.
+ * Copyright 2023 Oracle. All rights reserved.
+ */
+#include <sys/types.h>
+#include <sys/stat.h>
+#include <sys/ioctl.h>
+#include <linux/fs.h>
+#include <time.h>
+#include <stdlib.h>
+#include <unistd.h>
+#include <signal.h>
+#include <fcntl.h>
+#include <pthread.h>
+#include <stdio.h>
+#include <errno.h>
+#include <string.h>
+
+#ifndef FICLONE
+# define FICLONE _IOW(0x94, 9, int)
+#endif
+
+static pid_t mypid;
+
+static FILE *outcome_fp;
+
+/* Significant timestamps. Initialized to zero */
+static double program_start, clone_start, clone_end;
+
+/* Coordinates access to timestamps */
+static pthread_mutex_t lock = PTHREAD_MUTEX_INITIALIZER;
+
+struct readinfo {
+ int fd;
+ unsigned int blocksize;
+ char *descr;
+};
+
+struct cloneinfo {
+ int src_fd, dst_fd;
+};
+
+#define MSEC_PER_SEC 1000
+#define NSEC_PER_MSEC 1000000
+
+/*
+ * Assume that it shouldn't take longer than 100ms for the FICLONE ioctl to
+ * enter the kernel and take locks on an uncontended file. This is also the
+ * required CLOCK_MONOTONIC granularity.
+ */
+#define EARLIEST_READ_MS (MSEC_PER_SEC / 10)
+
+/*
+ * We want to be reasonably sure that the FICLONE takes long enough that any
+ * read initiated after clone operation locked the source file could have
+ * completed a disk IO before the clone finishes. Therefore, we require that
+ * the clone operation must take at least 4x the maximum setup time.
+ */
+#define MINIMUM_CLONE_MS (EARLIEST_READ_MS * 5)
+
+static double timespec_to_msec(const struct timespec *ts)
+{
+ return (ts->tv_sec * (double)MSEC_PER_SEC) +
+ (ts->tv_nsec / (double)NSEC_PER_MSEC);
+}
+
+static void sleep_ms(unsigned int len)
+{
+ struct timespec time = {
+ .tv_nsec = len * NSEC_PER_MSEC,
+ };
+
+ nanosleep(&time, NULL);
+}
+
+static void outcome(const char *str)
+{
+ fprintf(outcome_fp, "%s\n", str);
+ fflush(outcome_fp);
+}
+
+static void *reader_fn(void *arg)
+{
+ struct timespec now;
+ struct readinfo *ri = arg;
+ char *buf = malloc(ri->blocksize);
+ loff_t pos = 0;
+ ssize_t copied;
+ int ret;
+
+ if (!buf) {
+ perror("alloc buffer");
+ goto kill_error;
+ }
+
+ /* Wait for the FICLONE to start */
+ pthread_mutex_lock(&lock);
+ while (clone_start < program_start) {
+ pthread_mutex_unlock(&lock);
+#ifdef DEBUG
+ printf("%s read waiting for clone to start; cs=%.2f ps=%.2f\n",
+ ri->descr, clone_start, program_start);
+ fflush(stdout);
+#endif
+ sleep_ms(1);
+ pthread_mutex_lock(&lock);
+ }
+ pthread_mutex_unlock(&lock);
+ sleep_ms(EARLIEST_READ_MS);
+
+ /* Read from the file... */
+ while ((copied = read(ri->fd, buf, ri->blocksize)) > 0) {
+ double read_completion;
+
+ ret = clock_gettime(CLOCK_MONOTONIC, &now);
+ if (ret) {
+ perror("clock_gettime");
+ goto kill_error;
+ }
+ read_completion = timespec_to_msec(&now);
+
+ /*
+ * If clone_end is still zero, the FICLONE is still running.
+ * If the read completion occurred a safe duration after the
+ * start of the ioctl, then report that as an early read
+ * completion.
+ */
+ pthread_mutex_lock(&lock);
+ if (clone_end < program_start &&
+ read_completion > clone_start + EARLIEST_READ_MS) {
+ pthread_mutex_unlock(&lock);
+
+ /* clone still running... */
+ printf("finished %s read early at %.2fms\n",
+ ri->descr,
+ read_completion - program_start);
+ fflush(stdout);
+ outcome("finished read early");
+ goto kill_done;
+ }
+ pthread_mutex_unlock(&lock);
+
+ sleep_ms(1);
+ pos += copied;
+ }
+ if (copied < 0) {
+ perror("read");
+ goto kill_error;
+ }
+
+ return NULL;
+kill_error:
+ outcome("reader error");
+kill_done:
+ kill(mypid, SIGTERM);
+ return NULL;
+}
+
+static void *clone_fn(void *arg)
+{
+ struct timespec now;
+ struct cloneinfo *ci = arg;
+ int ret;
+
+ /* Record the approximate start time of this thread */
+ ret = clock_gettime(CLOCK_MONOTONIC, &now);
+ if (ret) {
+ perror("clock_gettime clone start");
+ goto kill_error;
+ }
+ pthread_mutex_lock(&lock);
+ clone_start = timespec_to_msec(&now);
+ pthread_mutex_unlock(&lock);
+
+ printf("started clone at %.2fms\n", clone_start - program_start);
+ fflush(stdout);
+
+ /* Kernel call, only killable with a fatal signal */
+ ret = ioctl(ci->dst_fd, FICLONE, ci->src_fd);
+ if (ret) {
+ perror("FICLONE");
+ goto kill_error;
+ }
+
+ /* If the ioctl completes, note the completion time */
+ ret = clock_gettime(CLOCK_MONOTONIC, &now);
+ if (ret) {
+ perror("clock_gettime clone end");
+ goto kill_error;
+ }
+
+ pthread_mutex_lock(&lock);
+ clone_end = timespec_to_msec(&now);
+ pthread_mutex_unlock(&lock);
+
+ printf("finished clone at %.2fms\n",
+ clone_end - program_start);
+ fflush(stdout);
+
+ /* Complain if we didn't take long enough to clone. */
+ if (clone_end < clone_start + MINIMUM_CLONE_MS) {
+ printf("clone did not take enough time (%.2fms)\n",
+ clone_end - clone_start);
+ fflush(stdout);
+ outcome("clone too fast");
+ goto kill_done;
+ }
+
+ outcome("clone finished before any reads");
+ goto kill_done;
+
+kill_error:
+ outcome("clone error");
+kill_done:
+ kill(mypid, SIGTERM);
+ return NULL;
+}
+
+int main(int argc, char *argv[])
+{
+ struct cloneinfo ci;
+ struct readinfo bufio = { .descr = "buffered" };
+ struct readinfo directio = { .descr = "directio" };
+ struct timespec now;
+ pthread_t clone_thread, bufio_thread, directio_thread;
+ double clockres;
+ int ret;
+
+ if (argc != 4) {
+ printf("Usage: %s src_file dst_file outcome_file\n", argv[0]);
+ return 1;
+ }
+
+ mypid = getpid();
+
+ /* Check for sufficient clock precision. */
+ ret = clock_getres(CLOCK_MONOTONIC, &now);
+ if (ret) {
+ perror("clock_getres MONOTONIC");
+ return 2;
+ }
+ printf("CLOCK_MONOTONIC resolution: %llus %luns\n",
+ (unsigned long long)now.tv_sec,
+ (unsigned long)now.tv_nsec);
+ fflush(stdout);
+
+ clockres = timespec_to_msec(&now);
+ if (clockres > EARLIEST_READ_MS) {
+ fprintf(stderr, "insufficient CLOCK_MONOTONIC resolution\n");
+ return 2;
+ }
+
+ /*
+ * Measure program start time since the MONOTONIC time base is not
+ * all that well defined.
+ */
+ ret = clock_gettime(CLOCK_MONOTONIC, &now);
+ if (ret) {
+ perror("clock_gettime MONOTONIC");
+ return 2;
+ }
+ if (now.tv_sec == 0 && now.tv_nsec == 0) {
+ fprintf(stderr, "Uhoh, start time is zero?!\n");
+ return 2;
+ }
+ program_start = timespec_to_msec(&now);
+
+ outcome_fp = fopen(argv[3], "w");
+ if (!outcome_fp) {
+ perror(argv[3]);
+ return 2;
+ }
+
+ /* Open separate fds for each thread */
+ ci.src_fd = open(argv[1], O_RDONLY);
+ if (ci.src_fd < 0) {
+ perror(argv[1]);
+ return 2;
+ }
+
+ ci.dst_fd = open(argv[2], O_RDWR | O_CREAT, 0600);
+ if (ci.dst_fd < 0) {
+ perror(argv[2]);
+ return 2;
+ }
+
+ bufio.fd = open(argv[1], O_RDONLY);
+ if (bufio.fd < 0) {
+ perror(argv[1]);
+ return 2;
+ }
+ bufio.blocksize = 37;
+
+ directio.fd = open(argv[1], O_RDONLY | O_DIRECT);
+ if (directio.fd < 0) {
+ perror(argv[1]);
+ return 2;
+ }
+ directio.blocksize = 512;
+
+ /* Start threads */
+ ret = pthread_create(&clone_thread, NULL, clone_fn, &ci);
+ if (ret) {
+ fprintf(stderr, "create clone thread: %s\n", strerror(ret));
+ return 2;
+ }
+
+ ret = pthread_create(&bufio_thread, NULL, reader_fn, &bufio);
+ if (ret) {
+ fprintf(stderr, "create bufio thread: %s\n", strerror(ret));
+ return 2;
+ }
+
+ ret = pthread_create(&directio_thread, NULL, reader_fn, &directio);
+ if (ret) {
+ fprintf(stderr, "create directio thread: %s\n", strerror(ret));
+ return 2;
+ }
+
+ /* Wait for threads */
+ ret = pthread_join(clone_thread, NULL);
+ if (ret) {
+ fprintf(stderr, "join clone thread: %s\n", strerror(ret));
+ return 2;
+ }
+
+ ret = pthread_join(bufio_thread, NULL);
+ if (ret) {
+ fprintf(stderr, "join bufio thread: %s\n", strerror(ret));
+ return 2;
+ }
+
+ ret = pthread_join(directio_thread, NULL);
+ if (ret) {
+ fprintf(stderr, "join directio thread: %s\n", strerror(ret));
+ return 2;
+ }
+
+ printf("Program should have killed itself?\n");
+ outcome("program failed to end early");
+ return 0;
+}
diff --git a/tests/generic/1953 b/tests/generic/1953
new file mode 100755
index 0000000000..058538e6fe
--- /dev/null
+++ b/tests/generic/1953
@@ -0,0 +1,74 @@
+#! /bin/bash
+# SPDX-License-Identifier: GPL-2.0
+# Copyright (c) 2023, Oracle and/or its affiliates. All Rights Reserved.
+#
+# FS QA Test No. 1953
+#
+# Race file reads with a very slow reflink operation to see if the reads
+# actually complete while the reflink is ongoing. This is a functionality
+# test for XFS commit f3ba4762fa56 "xfs: allow read IO and FICLONE to run
+# concurrently".
+#
+. ./common/preamble
+_begin_fstest auto clone punch
+
+# Import common functions.
+. ./common/filter
+. ./common/attr
+. ./common/reflink
+
+# real QA test starts here
+_require_scratch_reflink
+_require_cp_reflink
+_require_xfs_io_command "fpunch"
+_require_test_program "punch-alternating"
+_require_test_program "t_reflink_read_race"
+
+rm -f "$seqres.full"
+
+echo "Format and mount"
+_scratch_mkfs > "$seqres.full" 2>&1
+_scratch_mount >> "$seqres.full" 2>&1
+
+testdir="$SCRATCH_MNT/test-$seq"
+mkdir "$testdir"
+
+calc_space() {
+ blocks_needed=$(( 2 ** (fnr + 1) ))
+ space_needed=$((blocks_needed * blksz * 5 / 4))
+}
+
+# Figure out the number of blocks that we need to get the reflink runtime above
+# 1 seconds
+echo "Create a many-block file"
+for ((fnr = 1; fnr < 40; fnr++)); do
+ free_blocks=$(stat -f -c '%a' "$testdir")
+ blksz=$(_get_file_block_size "$testdir")
+ space_avail=$((free_blocks * blksz))
+ calc_space
+ test $space_needed -gt $space_avail && \
+ _notrun "Insufficient space for stress test; would only create $blocks_needed extents."
+
+ off=$(( (2 ** fnr) * blksz))
+ $XFS_IO_PROG -f -c "pwrite -S 0x61 -b 4194304 $off $off" "$testdir/file1" >> "$seqres.full"
+ "$here/src/punch-alternating" "$testdir/file1" >> "$seqres.full"
+
+ timeout 1s cp --reflink=always "$testdir/file1" "$testdir/garbage" || break
+done
+echo "fnr=$fnr" >> $seqres.full
+
+echo "Reflink the big file"
+$here/src/t_reflink_read_race "$testdir/file1" "$testdir/file2" \
+ "$testdir/outcome" &>> $seqres.full
+
+if [ ! -e "$testdir/outcome" ]; then
+ echo "Could not set up program"
+elif grep -q "finished read early" "$testdir/outcome"; then
+ echo "test completed successfully"
+else
+ cat "$testdir/outcome"
+fi
+
+# success, all done
+status=0
+exit
diff --git a/tests/generic/1953.out b/tests/generic/1953.out
new file mode 100644
index 0000000000..8eaacb7ff0
--- /dev/null
+++ b/tests/generic/1953.out
@@ -0,0 +1,6 @@
+QA output created by 1953
+Format and mount
+Create a many-block file
+Reflink the big file
+Terminated
+test completed successfully
