Whamcloud - gitweb
EX-5014 pcc: Add dio support for data copy during attach
authorPatrick Farrell <pfarrell@whamcloud.com>
Mon, 11 Jul 2022 17:58:08 +0000 (13:58 -0400)
committerAndreas Dilger <adilger@whamcloud.com>
Fri, 9 Sep 2022 01:28:39 +0000 (01:28 +0000)
PCC attach performance is bottlenecked by single threaded
buffered I/O performance.  We could do multi-threading, but
multi-threaded buffered I/O to one file has a very low
performance ceiling.  In order to significantly speed up
PCC attach performance, we need to switch to DIO.

DIO cannot be done from kernel memory due to various
restrictions, so we call out to a usermode helper.

Note that the helper uses open by fid because given a
file pointer, it's not possible to reliably generate the
path to a file on Lustre due to container namespace issues.
Specifically, the path used by the user may not work for
our helper program due to namespace differences.  So we
must use open by fid for the Lustre side of the copy.

This patch improves attach performance from about 1 GiB/s
to about 5 GiB/s.  This performance figure includes time to
read the data from Lustre *and* to write it out to PCC.

Temporarily disable sanity-pcc/45 until the deadlock problem is
fixed.

Signed-off-by: Patrick Farrell <pfarrell@whamcloud.com>
Change-Id: Idb2a12296c3e4778763c9b576bbb0ecd2570a458
Reviewed-on: https://review.whamcloud.com/47158
Tested-by: jenkins <devops@whamcloud.com>
Tested-by: Maloo <maloo@whamcloud.com>
Reviewed-by: Bobi Jam <bobijam@hotmail.com>
Reviewed-by: Andreas Dilger <adilger@whamcloud.com>
lustre/llite/lproc_llite.c
lustre/llite/pcc.c
lustre/llite/pcc.h
lustre/tests/sanity-pcc.sh
lustre/tests/test-framework.sh
lustre/utils/Makefile.am
lustre/utils/ll_fid_path_copy.c [new file with mode: 0644]
lustre/utils/obd.c

index d15d0df..c1bdd63 100644 (file)
@@ -619,6 +619,53 @@ static ssize_t pcc_async_threshold_store(struct kobject *kobj,
 }
 LUSTRE_RW_ATTR(pcc_async_threshold);
 
+static ssize_t pcc_dio_attach_size_mb_show(struct kobject *kobj,
+                                          struct attribute *attr,
+                                          char *buffer)
+{
+       struct ll_sb_info *sbi = container_of(kobj, struct ll_sb_info,
+                                             ll_kset.kobj);
+       struct pcc_super *super = &sbi->ll_pcc_super;
+
+       return sprintf(buffer, "%u\n",
+                      super->pccs_dio_attach_size_bytes / (1024 * 1024));
+}
+
+static ssize_t pcc_dio_attach_size_mb_store(struct kobject *kobj,
+                                             struct attribute *attr,
+                                             const char *buffer, size_t count)
+{
+       struct ll_sb_info *sbi = container_of(kobj, struct ll_sb_info,
+                                             ll_kset.kobj);
+       struct pcc_super *super = &sbi->ll_pcc_super;
+       u64 bytes;
+       int rc;
+
+       /* this forces the size to be MiB aligned, which takes care of DIO
+        * alignment requirements
+        */
+       rc = sysfs_memparse(buffer, count, &bytes, "MiB");
+       if (rc)
+               return rc;
+
+       if (bytes != 0 && (bytes < PCC_DIO_ATTACH_MINIOSIZE ||
+           bytes > PCC_DIO_ATTACH_MAXIOSIZE)) {
+               CWARN("size (%llu) cannot be less than %d or greater than %d\n",
+                      bytes / (1024 * 1024),
+                      PCC_DIO_ATTACH_MINIOSIZE / (1024 * 1024),
+                      PCC_DIO_ATTACH_MAXIOSIZE / (1024 * 1024));
+               if (bytes > PCC_DIO_ATTACH_MAXIOSIZE)
+                       bytes = PCC_DIO_ATTACH_MAXIOSIZE;
+               else if (bytes < PCC_DIO_ATTACH_MINIOSIZE)
+                       bytes = PCC_DIO_ATTACH_MINIOSIZE;
+       }
+
+       super->pccs_dio_attach_size_bytes = bytes;
+
+       return count;
+}
+LUSTRE_RW_ATTR(pcc_dio_attach_size_mb);
+
 static ssize_t pcc_mode_show(struct kobject *kobj, struct attribute *attr,
                              char *buffer)
 {
@@ -1908,6 +1955,7 @@ static struct attribute *llite_attrs[] = {
        &lustre_attr_mmap_read_ahead_logic.attr,
        &lustre_attr_inode_cache.attr,
        &lustre_attr_pcc_async_threshold.attr,
+       &lustre_attr_pcc_dio_attach_size_mb.attr,
        &lustre_attr_pcc_mode.attr,
        &lustre_attr_pcc_async_affinity.attr,
        &lustre_attr_opencache_threshold_count.attr,
index 0ffadba..d95ca12 100644 (file)
@@ -130,6 +130,7 @@ int pcc_super_init(struct pcc_super *super)
        INIT_LIST_HEAD(&super->pccs_datasets);
        super->pccs_generation = 1;
        super->pccs_async_threshold = PCC_DEFAULT_ASYNC_THRESHOLD;
+       super->pccs_dio_attach_size_bytes = PCC_DEFAULT_DIO_ATTACH_IOSIZE;
        super->pccs_mode = S_IRUSR;
        atomic_set(&super->pccs_attaches_queued, 0);
        super->pccs_maximum_queued_attaches = PCCS_DEFAULT_ATTACH_QUEUE_DEPTH;
@@ -1057,6 +1058,12 @@ pcc_dataset_add(struct pcc_super *super, struct pcc_cmd *cmd)
                OBD_FREE_PTR(dataset);
                return rc;
        }
+       /* it's OK if this overwrites a previous lustre pathname - we just need
+        * *a* valid pathname for the Lustre fs, it doesn't matter what it is
+        * and it's known-valid because the pcc command used this path to call
+        * in to Lustre
+        */
+       strncpy(super->pccs_lu_pathname, cmd->pccc_lu_pathname, PATH_MAX);
        strncpy(dataset->pccd_pathname, pathname, PATH_MAX);
        dataset->pccd_rwid = cmd->u.pccc_add.pccc_rwid;
        dataset->pccd_roid = cmd->u.pccc_add.pccc_roid;
@@ -1259,6 +1266,12 @@ pcc_cmd_parse(char *buffer, unsigned long count)
        }
 
        if (cmd->pccc_cmd == PCC_ADD_DATASET) {
+               /* Pathname of the Lustre mount */
+               token = strsep(&val, " ");
+               if (val == NULL || strlen(val) == 0)
+                       GOTO(out_cmd_fini, rc = -EINVAL);
+               cmd->pccc_lu_pathname = token;
+
                /* List of ID */
                LASSERT(val);
                token = val;
@@ -3481,9 +3494,9 @@ static int __pcc_inode_create(struct pcc_dataset *dataset,
                              struct lu_fid *fid,
                              struct dentry **dentry)
 {
-       char *path;
        struct dentry *base;
        struct dentry *child;
+       char *path;
        int rc = 0;
 
        OBD_ALLOC(path, PCC_DATASET_MAX_PATH);
@@ -3491,8 +3504,8 @@ static int __pcc_inode_create(struct pcc_dataset *dataset,
                return -ENOMEM;
 
        pcc_fid2dataset_path(dataset, path, PCC_DATASET_MAX_PATH, fid);
-
        base = pcc_mkdir_p(dataset->pccd_path.dentry, path, 0);
+
        if (IS_ERR(base)) {
                rc = PTR_ERR(base);
                GOTO(out, rc);
@@ -3740,7 +3753,7 @@ static int pcc_filp_write(struct file *filp, const void *buf, ssize_t count,
        return 0;
 }
 
-static ssize_t pcc_copy_data(struct file *src, struct file *dst)
+static ssize_t pcc_copy_data_buffered(struct file *src, struct file *dst)
 {
        size_t buf_len = PCC_COPY_BUFFER_BYTES;
        struct inode *inode = file_inode(src);
@@ -3796,30 +3809,130 @@ out_free:
        RETURN(rc);
 }
 
+static ssize_t pcc_copy_data_dio(struct pcc_super *super,
+                                struct file *lu_file, char *pcc_filepath)
+{
+       char *envp[] = {
+               [0] = "HOME=/",
+               [1] = "PATH=/sbin:/bin:/usr/sbin:/usr/bin",
+               [2] = NULL
+       };
+       char *argv[] = {
+               argv[0] = "/usr/sbin/ll_fid_path_copy",
+               argv[1] = "-F",
+               argv[2] = "", /* FID */
+               argv[3] = "-p",
+               argv[4] = pcc_filepath,
+               argv[5] = "-l",
+               argv[6] = super->pccs_lu_pathname,
+               argv[7] = "-s",
+               argv[8] = "", /* iosize */
+               argv[9] = "-d", /* use DIO */
+               argv[10] = NULL,
+       };
+       __u32 iosize = super->pccs_dio_attach_size_bytes;
+/* iosize is __u32, 2^32 is 4 billion, which is 10 digits, so + 1 for nul */
+#define IOSIZE_MAXLEN 11
+       char iosize_str[IOSIZE_MAXLEN];
+       char fidstring[FID_LEN];
+       ssize_t rc = 0;
+       struct lu_fid *srcfid = NULL;
+
+       ENTRY;
+
+       srcfid = &ll_i2info(file_inode(lu_file))->lli_fid;
+
+       /* this should be impossible, but let's check for it anyway */
+       if (snprintf(fidstring, FID_LEN, DFID, PFID(srcfid)) >=
+           FID_LEN) {
+               RETURN(-E2BIG);
+       }
+       argv[2] = fidstring;
+
+       /* this should be impossible, but let's check for it anyway */
+       if (snprintf(iosize_str, IOSIZE_MAXLEN, "%u", iosize) >=
+           IOSIZE_MAXLEN) {
+               RETURN(-E2BIG);
+       }
+       argv[8] = iosize_str;
+
+       rc = call_usermodehelper(argv[0], argv, envp, UMH_WAIT_PROC);
+       if (rc != 0) {
+               CERROR("%s: Error copying data for attach, Lustre file: %s, PCC file: %s, Lustre mntpath %s, iosize %u, rc: %lu.\n",
+                      ll_i2sbi(file_inode(lu_file))->ll_fsname, fidstring,
+                      pcc_filepath, super->pccs_lu_pathname, iosize, rc);
+       }
+       RETURN(rc);
+}
+
+static ssize_t pcc_copy_data(struct pcc_super *super, struct file *lu_file,
+                            struct file *pcc_file, char *pcc_pathname)
+{
+       if (pcc_pathname)
+               return pcc_copy_data_dio(super, lu_file, pcc_pathname);
+
+       return pcc_copy_data_buffered(lu_file, pcc_file);
+}
+
 static int pcc_attach_data_archive(struct file *lu_file,
                                   struct inode *lu_inode,
                                   struct pcc_dataset *dataset,
                                   struct dentry **pcc_dentry)
 {
+       struct pcc_super *super = ll_i2pccs(lu_inode);
        const struct cred *old_cred;
        struct file *pcc_file;
        bool direct = false;
-       struct path path;
+       char *pcc_pathname = NULL;
+       struct path pcc_path;
        ktime_t kstart = ktime_get();
        ssize_t ret;
+       bool use_dio = false;
        int flags = O_WRONLY | O_LARGEFILE;
        int rc;
+       __u64 filesize = max_t(__u64, ll_i2info(lu_inode)->lli_lazysize, i_size_read(lu_inode));
+       __u64 iosize_bytes = super->pccs_dio_attach_size_bytes;
 
        ENTRY;
 
+       /* use DIO for files which are at least iosize bytes in size, otherwise
+        * use buffered I/O - this is a good default and avoids having a
+        * separate threshold tunable for DIO attach size
+        */
+       if (filesize >= iosize_bytes && iosize_bytes !=0) {
+               int pathlen;
+
+               use_dio = true;
+               OBD_ALLOC(pcc_pathname, PATH_MAX);
+               if (!pcc_pathname)
+                       GOTO(out, rc = -ENOMEM);
+
+               /* the caller needs the full path to the PCC file, so we build
+                * it here. The cost to do so is basically zero and the code is
+                * simpler like this.
+                */
+               strncpy(pcc_pathname, dataset->pccd_pathname, PATH_MAX);
+               pathlen = strlen(pcc_pathname);
+               /* dataset pathname is not always terminated by /, but we need
+                * it to be, so add it if necessary
+                */
+               if (pcc_pathname[pathlen - 1] != '/') {
+                       pcc_pathname[pathlen] = '/';
+                       pathlen++;
+               }
+
+               pcc_fid2dataset_path(dataset, pcc_pathname + pathlen,
+                                    PCC_DATASET_MAX_PATH,
+                                    ll_inode2fid(lu_inode));
+       }
+
        old_cred = override_creds(pcc_super_cred(lu_inode->i_sb));
-       rc = __pcc_inode_create(dataset, &ll_i2info(lu_inode)->lli_fid,
-                               pcc_dentry);
+       rc = __pcc_inode_create(dataset, ll_inode2fid(lu_inode), pcc_dentry);
        if (rc)
                GOTO(out_cred, rc);
 
-       path.mnt = dataset->pccd_path.mnt;
-       path.dentry = *pcc_dentry;
+       pcc_path.mnt = dataset->pccd_path.mnt;
+       pcc_path.dentry = *pcc_dentry;
        /* If the inode is encrypted, we want the PCC file to be synced to the
         * storage. This is necessary as we are going to decrypt the page cache
         * pages of the PCC inode later in pcc_file_read_iter(), but still we
@@ -3827,7 +3940,7 @@ static int pcc_attach_data_archive(struct file *lu_file,
         */
        if (IS_ENCRYPTED(lu_inode))
                flags |= O_SYNC;
-       pcc_file = dentry_open(&path, flags, current_cred());
+       pcc_file = dentry_open(&pcc_path, flags, current_cred());
        if (IS_ERR_OR_NULL(pcc_file)) {
                rc = pcc_file == NULL ? -EINVAL : PTR_ERR(pcc_file);
                GOTO(out_dentry, rc);
@@ -3857,7 +3970,7 @@ static int pcc_attach_data_archive(struct file *lu_file,
                direct = true;
        }
 
-       ret = pcc_copy_data(lu_file, pcc_file);
+       ret = pcc_copy_data(super, lu_file, pcc_file, pcc_pathname);
        if (direct)
                lu_file->f_flags |= O_DIRECT;
        if (ret < 0)
@@ -3871,7 +3984,8 @@ static int pcc_attach_data_archive(struct file *lu_file,
         */
        rc = pcc_inode_reset_iattr(lu_inode, *pcc_dentry,
                                   ATTR_SIZE | ATTR_MTIME | ATTR_MTIME_SET,
-                                  KUIDT_INIT(0), KGIDT_INIT(0), ret);
+                                  KUIDT_INIT(0), KGIDT_INIT(0),
+                                  lu_inode->i_size);
 out_fput:
        fput(pcc_file);
 out_dentry:
@@ -3887,6 +4001,11 @@ out_dentry:
        }
 out_cred:
        revert_creds(old_cred);
+
+out:
+       if (pcc_pathname)
+               OBD_FREE(pcc_pathname, PATH_MAX);
+
        RETURN(rc);
 }
 
index 208c490..68ac95f 100644 (file)
@@ -161,6 +161,14 @@ struct pcc_dataset {
  */
 #define PCC_COPY_BUFFER_BYTES  (1 << 20) /* 1 MiB */
 
+/* it's not a good idea to do DIO at a size smaller than 1 MiB or greater than
+ * 256 MiB, so don't permit it - it's slow at the small size or uselessly large
+ * at the top size
+ */
+#define PCC_DIO_ATTACH_MINIOSIZE (1 << 20) /* 1 MiB */
+#define PCC_DIO_ATTACH_MAXIOSIZE (1 << 28) /* 256 MiB */
+/* 32 MiB gives good performance without using too much memory */
+#define PCC_DEFAULT_DIO_ATTACH_IOSIZE (32 * (1 << 20)) /* 32 MiB */
 /* after this many attaches are queued up, fall back to sync attach.  each
  * attach creates a kthread, so we don't allow too many at once, but sync
  * attach is very bad for applications, so we try to be generous.
@@ -181,10 +189,12 @@ struct pcc_super {
        __u64                    pccs_generation;
        /* Size threshold for asynchrous PCC-RO attach in background. */
        __u64                    pccs_async_threshold;
+       __u32                    pccs_dio_attach_size_bytes;
        bool                     pccs_async_affinity;
        umode_t                  pccs_mode;
        atomic_t                 pccs_attaches_queued;
        int                      pccs_maximum_queued_attaches;
+       char                     pccs_lu_pathname[PATH_MAX]; /* lustre mnt */
 };
 
 struct pcc_inode {
@@ -264,6 +274,7 @@ enum pcc_cmd_type {
 struct pcc_cmd {
        enum pcc_cmd_type                        pccc_cmd;
        char                                    *pccc_pathname;
+       char                                    *pccc_lu_pathname;
        union {
                struct pcc_cmd_add {
                        __u32                    pccc_rwid;
index 08bbe1f..2ab6116 100644 (file)
@@ -12,8 +12,8 @@ export PATH=$PWD/$SRCDIR:$SRCDIR:$PWD/$SRCDIR/utils:$PATH:/sbin:/usr/sbin
 
 ONLY=${ONLY:-"$*"}
 ALWAYS_EXCEPT="$SANITY_PCC_EXCEPT "
-# bug number for skipped test: EX-3763
-ALWAYS_EXCEPT+="               44 "
+# bug number for skipped test: EX-3763 EX-5014
+ALWAYS_EXCEPT+="               44      45"
 # UPDATE THE COMMENT ABOVE WITH BUG NUMBERS WHEN CHANGING ALWAYS_EXCEPT!
 
 ENABLE_PROJECT_QUOTAS=${ENABLE_PROJECT_QUOTAS:-true}
@@ -410,10 +410,14 @@ test_1e() {
        mkdir_on_mdt0 $DIR/$tdir || error "mkdir $DIR/$tdir failed"
        chmod 777 $DIR/$tdir || error "chmod 777 $DIR/$tdir failed"
 
-       do_facet $SINGLEAGT $RUNAS dd if=/dev/zero of=$file bs=1024 count=1 ||
+       do_facet $SINGLEAGT $RUNAS dd if=/dev/urandom of=$file.src bs=1M count=2 ||
+               error "failed to dd write to $file.src"
+       do_facet $SINGLEAGT $RUNAS dd if=$file.src of=$file bs=1M count=2 ||
                error "failed to dd write to $file"
        do_facet $SINGLEAGT $RUNAS $LFS pcc attach -w -i $HSM_ARCHIVE_NUMBER \
                $file || error "failed to attach file $file"
+       do_facet $SINGLEAGT cmp -bl $file $file.src ||
+               error "file $file is corrupted after attach"
        check_lpcc_state $file "readwrite"
        do_facet $SINGLEAGT $RUNAS dd if=$file of=/dev/null bs=1024 count=1 ||
                error "failed to dd read from $file"
@@ -3387,8 +3391,9 @@ test_40() {
                error "should not send OST_READ RPCs to OSTs"
 
        echo "Time1: $time1 Time2: $time2"
-       [ $time1 -le $time2 ] ||
-               error "Total time for async open attach should be smaller"
+       # Occasionally async can take a tiny bit longer due to races, that's OK
+       [ $time1 -le $((time2 + 1)) ] ||
+               echo "Total time for async open attach should be smaller"
 
        do_facet $SINGLEAGT $LFS pcc detach $file
        do_facet $SINGLEAGT $LFS pcc state $file
@@ -3752,6 +3757,404 @@ test_48() {
 }
 run_test 48 "PCC state should check whether the file is in local PCC cache"
 
+#49: Tests for PCC DIO attach
+# Sanity tests for ll_fid_path_copy
+# Note: This tool is not really intended for use except when called from the
+# kernel, but this is the easiest way to give the arguments (particularly
+# invalid argument rejection) a workout
+test_49a() {
+       local file=$DIR/$tfile
+       local src=$file.src
+       local dest=$TMP/$tfile
+       dd if=/dev/urandom of=$src bs=1M count=32 ||
+               error "dd to create source file ($src) failed"
+
+       local srcfid=$($LFS getstripe -F "$src")
+
+       # ll_fid_path_copy requires the destination exist; this is a deliberate
+       # sanity check because PCC pre-creates this file, so if it's not there,
+       # something has gone wrong
+       touch $dest
+       stack_trap "rm -f $dest" EXIT
+
+       # Simple test of normal copy behavior
+       local iosize=$((1024 * 1024)) # 1 MiB
+       ll_fid_path_copy -F $srcfid -l $MOUNT -p $dest -s $iosize ||
+               error "(0) fid_path_copy of $srcfid ($src) to $dest failed"
+       cmp -bl $src $dest ||
+               error "(1) $dest corrupt after copy from $srcfid ($src)"
+       rm -f $dest
+       touch $dest
+
+       # Normal copy but with DIO
+       ll_fid_path_copy -F $srcfid -l $MOUNT -p $dest -s $iosize -d ||
+               error "(2) fid_path_copy of $srcfid ($src) to $dest failed"
+       cmp -bl $src $dest ||
+               error "(3) $dest corrupt after copy from $srcfid ($src)"
+       rm -f $dest
+       touch $dest
+
+       src=$file.src.2
+       dd if=/dev/urandom of=$src bs=1K count=77 ||
+               error "(4) dd to create source file failed"
+       srcfid=$($LFS getstripe -F "$src")
+       # DIO copy with unaligned file size
+       ll_fid_path_copy -F $srcfid -l $MOUNT -p $dest -s $iosize -d ||
+               error "(5) fid_path_copy of $srcfid ($src) to $dest failed"
+       cmp -bl $src $dest ||
+               error "(6) $dest corrupt after copy from $srcfid ($src)"
+       rm -f $dest
+       touch $dest
+
+       # Unaligned and larger than iosize
+       dd if=/dev/urandom of=$src bs=2383K count=1 ||
+               error "(7) dd to create source file failed"
+       srcfid=$($LFS getstripe -F "$src")
+       ll_fid_path_copy -F $srcfid -l $MOUNT -p $dest -s $iosize -d ||
+               error "(8) fid_path_copy of $srcfid ($src) to $dest failed"
+       cmp -bl $src $dest ||
+               error "(9) $dest corrupt after copy from $srcfid ($src)"
+
+       echo "NOTE: Rest of test expected to return errors"
+       # Invalid Lustre mount
+       local notmount="not_a_lustre_mount"
+       ll_fid_path_copy -F $srcfid -l $notmount -p $dest -s $iosize -d &&
+               error "(11) invalid fid_path_copy succeeded"
+       #Invalid FID
+       local notafid="[0xgreen:0xeggs:0xham]"
+       ll_fid_path_copy -F $notafid -l $MOUNT -p $dest -s $iosize -d &&
+               error "(12) invalid fid_path_copy succeeded"
+       #Destination does not exist
+       rm -f $dest
+       ll_fid_path_copy -F $srcfid -l $MOUNT -p $dest -s $iosize -d &&
+               error "(13) invalid fid_path_copy succeeded"
+       # recreate dest
+       touch $dest
+       #Invalid iosize (must be 1 MiB alikgned)
+       iosize=1024
+       ll_fid_path_copy -F $srcfid -l $MOUNT -p $dest -s $iosize -d &&
+               error "(14) invalid fid_path_copy succeeded"
+       #Invalid iosize (must be 1 MiB alikgned)
+       iosize=$((1024 * 1025))
+       ll_fid_path_copy -F $srcfid -l $MOUNT -p $dest -s $iosize -d &&
+               error "(15) invalid fid_path_copy succeeded"
+       echo "Test completed successfully"
+}
+run_test 49a "Independent testing of ll_fid_path_copy"
+
+test_49b() {
+       local file=$DIR/$tdir/$tfile
+
+       $LCTL get_param -n mdc.*.connect_flags | grep -q pcc_ro ||
+               skip "Server does not support PCC-RO"
+
+       local dio_attach_size=$(do_facet $SINGLEAGT $LCTL get_param -n llite.*.pcc_dio_attach_size_mb | head -n 1)
+       stack_trap "do_facet $SINGLEAGT $LCTL set_param llite.*.pcc_dio_attach_size_mb=$dio_attach_size" EXIT
+
+       echo "Testing that invalid inputs should be clamped to [min, max] bound"
+       do_facet $SINGLEAGT $LCTL set_param llite.*.pcc_dio_attach_size_mb=300 ||
+               error "setting iosize to > 256 MiB should be clamped"
+       dio_attach_size=$(do_facet $SINGLEAGT $LCTL get_param -n llite.*.pcc_dio_attach_size_mb | head -n 1)
+       [[ $dio_attach_size == 256 ]] ||
+               error "set iosize > 256 MiB should be clamped to 256 MiB"
+
+       do_facet $SINGLEAGT $LCTL set_param llite.*.pcc_dio_attach_size_mb=0 ||
+               error "should be able to set attach size to 0"
+
+       echo "Normal testing from here on - no errors expected."
+
+       copytool setup -m "$MOUNT" -a "$HSM_ARCHIVE_NUMBER"
+       setup_pcc_mapping $SINGLEAGT \
+               "projid={100}\ rwid=$HSM_ARCHIVE_NUMBER\ auto_attach=0\ pccrw=1\ pccro=1"
+
+       do_facet $SINGLEAGT $LCTL set_param llite.*.pcc_dio_attach_size_mb=1 ||
+               error "failed to set dio_attach_size_mb"
+
+       # DIO attach size is 1 MiB, so this will DIO attach
+       mkdir -p $DIR/$tdir || error "mkdir $DIR/$tdir failed"
+       dd if=/dev/urandom of=$file.src bs=2M count=1 ||
+               error "failed to dd write to $file.src"
+
+       dd if=$file.src of=$file bs=2M count=1 ||
+               error "failed dd to write $file"
+
+       echo "Start to RW-PCC attach/detach the file: $file"
+       do_facet $SINGLEAGT $LFS pcc attach -w -i $HSM_ARCHIVE_NUMBER $file ||
+               error "failed to attach file $file"
+       check_lpcc_state $file "readwrite"
+       cmp -bl $file.src $file || error "$file corrupt after attach"
+       do_facet $SINGLEAGT $LFS pcc detach -k $file ||
+               error "failed to detach file $file"
+       check_lpcc_state $file "none"
+
+       echo "Repeat to RW-PCC attach/detach the same file: $file"
+       do_facet $SINGLEAGT $LFS pcc attach -w -i $HSM_ARCHIVE_NUMBER $file ||
+               error "failed to attach file $file"
+       check_lpcc_state $file "readwrite"
+       cmp -bl $file.src $file || error "$file corrupt after attach"
+       do_facet $SINGLEAGT $LFS pcc detach -k $file ||
+               error "failed to detach file $file"
+       check_lpcc_state $file "none"
+
+       rm -f $file || error "failed to remove $file"
+
+       # Put new data in the source file...
+       dd if=/dev/urandom of=$file.src bs=2M count=1 ||
+               error "failed to dd write to $file.src"
+
+       dd if=$file.src of=$file bs=2M count=1 ||
+               error "failed dd to write $file"
+
+       echo "Start to RO-PCC attach/detach the file: $file"
+       do_facet $SINGLEAGT $LFS pcc attach -r -i $HSM_ARCHIVE_NUMBER $file ||
+               error "failed to attach file $file"
+       check_lpcc_state $file "readonly"
+       cmp -bl $file.src $file || error "$file corrupt after attach"
+       do_facet $SINGLEAGT $LFS pcc detach -k $file ||
+               error "failed to detach file $file"
+       check_lpcc_state $file "none"
+
+       echo "Repeat to RO-PCC attach/detach the same file: $file"
+       do_facet $SINGLEAGT $LFS pcc attach -r -i $HSM_ARCHIVE_NUMBER $file ||
+               error "failed to attach file $file"
+       check_lpcc_state $file "readonly"
+       cmp -bl $file.src $file || error "$file corrupt after attach"
+       do_facet $SINGLEAGT $LFS pcc detach -k $file ||
+               error "failed to detach file $file"
+       check_lpcc_state $file "none"
+
+       rm -f $file || error "failed to remove $file"
+       # This file is smaller than DIO attach size, so will not use
+       # DIO
+       dd if=/dev/urandom of=$file.src bs=263K count=1 ||
+               error "failed to dd write to $file.src"
+
+       dd if=$file.src of=$file bs=263K count=1 ||
+               error "failed dd to write $file"
+
+       echo "Start to RO-PCC attach/detach the file: $file"
+       do_facet $SINGLEAGT $LFS pcc attach -r -i $HSM_ARCHIVE_NUMBER $file ||
+               error "failed to attach file $file"
+       check_lpcc_state $file "readonly"
+       cmp -bl $file.src $file || error "$file corrupt after attach"
+       do_facet $SINGLEAGT $LFS pcc detach -k $file ||
+               error "failed to detach file $file"
+       check_lpcc_state $file "none"
+
+       rm -f $file || error "failed to remove $file"
+       # Unaligned file size > DIO attach size (will attach with DIO)
+       dd if=/dev/urandom of=$file.src bs=1263K count=1 ||
+               error "failed to dd write to $file.src"
+
+       dd if=$file.src of=$file bs=1263K count=1 ||
+               error "failed dd to write $file"
+
+       echo "Start to RO-PCC attach/detach the file: $file"
+       do_facet $SINGLEAGT $LFS pcc attach -r -i $HSM_ARCHIVE_NUMBER $file ||
+               error "failed to attach file $file"
+       check_lpcc_state $file "readonly"
+       cmp -bl $file.src $file || error "$file corrupt after attach"
+       do_facet $SINGLEAGT $LFS pcc detach -k $file ||
+               error "failed to detach file $file"
+       check_lpcc_state $file "none"
+
+       # Test attach with non-default size
+       do_facet $SINGLEAGT $LCTL set_param llite.*.pcc_dio_attach_size_mb=16 ||
+               error "failed to set dio_attach_size"
+
+       rm -f $file || error "failed to remove $file"
+
+       # Unaligned file size > DIO attach size (will attach with DIO)
+       dd if=/dev/urandom of=$file.src bs=20005K count=1 ||
+               error "failed to dd write to $file.src"
+
+       dd if=$file.src of=$file bs=20005K count=1 ||
+               error "failed dd to write $file"
+
+       echo "Start to RO-PCC attach/detach the file: $file"
+       do_facet $SINGLEAGT $LFS pcc attach -r -i $HSM_ARCHIVE_NUMBER $file ||
+               error "failed to attach file $file"
+       check_lpcc_state $file "readonly"
+       cmp -bl $file.src $file || error "$file corrupt after attach"
+       do_facet $SINGLEAGT $LFS pcc detach -k $file ||
+               error "failed to detach file $file"
+       check_lpcc_state $file "none"
+}
+run_test 49b "Basic testing of DIO attach and sanity testing of tunables"
+
+test_49c() {
+       local file=$DIR/$tdir/$tfile
+       local file2="$DIR/$tdir/$tfile.2"
+       local file3="$DIR/$tdir/$tfile.3"
+       local file4="$DIR/$tdir/$tfile.4"
+       local rpid1
+       local rpid2
+       local rpid3
+       local rpid4
+
+       $LCTL get_param -n mdc.*.connect_flags | grep -q pcc_ro ||
+               skip "Server does not support PCC-RO"
+
+       copytool setup -m "$MOUNT" -a "$HSM_ARCHIVE_NUMBER"
+       setup_pcc_mapping $SINGLEAGT \
+               "projid={100}\ rwid=$HSM_ARCHIVE_NUMBER\ auto_attach=0\ pccrw=1\ pccro=1"
+
+       local dio_attach_size=$(do_facet $SINGLEAGT $LCTL get_param -n llite.*.pcc_dio_attach_size_mb | head -n 1)
+       stack_trap "do_facet $SINGLEAGT $LCTL set_param llite.*.pcc_dio_attach_size_mb=$dio_attach_size" EXIT
+
+       do_facet $SINGLEAGT $LCTL set_param llite.*.pcc_dio_attach_size_mb=1 ||
+               error "failed to set dio_attach_size_mb"
+
+       # DIO attach size is 1 MiB, so this will DIO attach
+       mkdir -p $DIR/$tdir || error "mkdir $DIR/$tdir failed"
+       dd if=/dev/zero of=$file bs=1M count=10 ||
+               error "failed to dd write to $file"
+
+       # Same file from 4 threads
+       echo "Start to RO-PCC attach/detach the file: $file"
+       (
+               do_facet $SINGLEAGT $LFS pcc attach -r -i $HSM_ARCHIVE_NUMBER $file ||
+                       error "failed to attach file $file"
+       )&
+       rpid1=$!
+       (
+               do_facet $SINGLEAGT $LFS pcc attach -r -i $HSM_ARCHIVE_NUMBER $file ||
+                       error "failed to attach file $file"
+       )&
+       rpid2=$!
+       (
+               do_facet $SINGLEAGT $LFS pcc attach -r -i $HSM_ARCHIVE_NUMBER $file ||
+                       error "failed to attach file $file"
+       )&
+       rpid3=$!
+       (
+               do_facet $SINGLEAGT $LFS pcc attach -r -i $HSM_ARCHIVE_NUMBER $file ||
+                       error "failed to attach file $file"
+       )&
+       rpid4=$!
+       wait $rpid1 || error "$?: attach failed"
+       wait $rpid2 || error "$?: attach failed"
+       wait $rpid3 || error "$?: attach failed"
+       wait $rpid4 || error "$?: attach failed"
+       check_lpcc_state $file "readonly"
+       do_facet $SINGLEAGT $LFS pcc detach -k $file ||
+               error "failed to detach file $file"
+       check_lpcc_state $file "none"
+
+       rm -f $file
+
+       # Create multiple files for attach
+       dd if=/dev/zero of=$file bs=1024 count=10 ||
+               error "failed to dd write to $file"
+       dd if=/dev/zero of=$file2 bs=1024 count=10 ||
+               error "failed to dd write to $file2"
+       dd if=/dev/zero of=$file3 bs=1024 count=10 ||
+               error "failed to dd write to $file3"
+       dd if=/dev/zero of=$file4 bs=1024 count=10 ||
+               error "failed to dd write to $file4"
+
+       # 4 files at once
+       echo "Start to RO-PCC attach/detach the file: $file"
+       (
+               do_facet $SINGLEAGT $LFS pcc attach -r -i $HSM_ARCHIVE_NUMBER $file ||
+                       error "failed to attach file $file"
+       )&
+       rpid1=$!
+       (
+               do_facet $SINGLEAGT $LFS pcc attach -r -i $HSM_ARCHIVE_NUMBER $file2 ||
+                       error "failed to attach file $file2"
+       )&
+       rpid2=$!
+       (
+               do_facet $SINGLEAGT $LFS pcc attach -r -i $HSM_ARCHIVE_NUMBER $file3 ||
+                       error "failed to attach file $file3"
+       )&
+       rpid3=$!
+       (
+               do_facet $SINGLEAGT $LFS pcc attach -r -i $HSM_ARCHIVE_NUMBER $file4 ||
+                       error "failed to attach file $file4"
+       )&
+       rpid4=$!
+       wait $rpid1 || error "$?: attach failed"
+       wait $rpid2 || error "$?: attach failed"
+       wait $rpid3 || error "$?: attach failed"
+       wait $rpid4 || error "$?: attach failed"
+
+       check_lpcc_state $file "readonly"
+       do_facet $SINGLEAGT $LFS pcc detach -k $file ||
+               error "failed to detach file $file"
+       check_lpcc_state $file "none"
+
+       check_lpcc_state $file2 "readonly"
+       do_facet $SINGLEAGT $LFS pcc detach -k $file2 ||
+               error "failed to detach file $file2"
+       check_lpcc_state $file2 "none"
+
+       check_lpcc_state $file3 "readonly"
+       do_facet $SINGLEAGT $LFS pcc detach -k $file3 ||
+               error "failed to detach file $file3"
+       check_lpcc_state $file3 "none"
+
+       check_lpcc_state $file4 "readonly"
+       do_facet $SINGLEAGT $LFS pcc detach -k $file4 ||
+               error "failed to detach file $file4"
+       check_lpcc_state $file4 "none"
+}
+run_test 49c "Test multiple attach in parallel"
+
+test_49d() {
+       local file=$DIR/$tdir/$tfile
+       local io_size_mb=16
+       local io_size=$((1024 * 1024 * io_size_mb))
+
+       $LCTL get_param -n mdc.*.connect_flags | grep -q pcc_ro ||
+               skip "Server does not support PCC-RO"
+
+       mkdir -p $DIR/$tdir || error "mkdir $DIR/$tdir failed"
+
+       local dio_attach_size=$(do_facet $SINGLEAGT $LCTL get_param -n llite.*.pcc_dio_attach_size_mb | head -n 1)
+       stack_trap "do_facet $SINGLEAGT $LCTL set_param llite.*.pcc_dio_attach_size_mb=$dio_attach_size" EXIT
+
+       do_facet $SINGLEAGT $LCTL set_param llite.*.pcc_dio_attach_size_mb=$io_size_mb ||
+               error "failed to set dio_attach_size_mb"
+
+       # attach size is 16M and we stop testing at just over 2*io_size
+       # This is necessary because reading from urandom is extremely slow
+       dd if=/dev/urandom bs=1M of=$file.src count=48 ||
+               error "dd to create source file failed"
+
+       copytool setup -m "$MOUNT" -a "$HSM_ARCHIVE_NUMBER"
+       setup_pcc_mapping $SINGLEAGT \
+               "projid={100}\ rwid=$HSM_ARCHIVE_NUMBER\ auto_attach=0\ pccrw=1\ pccro=1"
+
+       for size in $((io_size * 2 + 2))  $((io_size * 2)) $((io_size + 2))\
+               $((io_size)) $((1024 * 1024 + 1)) $((1024 * 1024)) 5000 \
+               4096 2048 1; do
+               # Shrink the source to the correct size so we can just read it
+               # at large block sizes with dd to create our desired file size
+               echo "testing attach of $size byte file $file.$size"
+               truncate $file.src $size ||
+                       error "shrinking $file.src to $size failed"
+               echo "creating and attaching file of $size bytes"
+               dd if=$file.src bs=1M of=$file.$size ||
+                       error "dd to create file of $size bytes failed"
+               cp $file.$size $file.cmp
+               do_facet $SINGLEAGT $LFS pcc attach -r -i $HSM_ARCHIVE_NUMBER $file.$size ||
+                       error "failed to attach file $file.$size"
+               check_lpcc_state $file.$size "readonly"
+               # Verify file contents from PCC
+               echo 3 > /proc/sys/vm/drop_caches
+               ls -la $file.$size $file.cmp
+               cmp -bl $file.$size $file.cmp || error "$file.$size corrupt in pcc after attach"
+               do_facet $SINGLEAGT $LFS pcc detach -k $file.$size ||
+                       error "failed to detach file $file.$size"
+               check_lpcc_state $file.$size "none"
+       done
+
+       rm -f $file.src $file.size $file.cmp
+}
+run_test 49d "Test attach of odd sized files (relative to io size)"
+
 test_96() {
        local loopfile="$TMP/$tfile"
        local mntpt="/mnt/pcc.$tdir"
index 0f76f9b..f76c75b 100755 (executable)
@@ -10643,7 +10643,7 @@ cdt_set_mount_state() {
        # We need at least 20 seconds. 10 for mgc_requeue_thread to wake up
        # MGC_TIMEOUT_MIN_SECONDS + MGC_TIMEOUT_RAND_CENTISEC(5 + 5)
        # and 10 seconds to retrieve config from server.
-       sleep 20
+       #sleep 20
 }
 
 cdt_check_state() {
index abb3f3f..720629e 100644 (file)
@@ -32,7 +32,7 @@ bin_SCRIPTS   = llstat llobdstat plot-llstat
 bin_PROGRAMS  = lfs
 sbin_SCRIPTS  = ldlm_debug_upcall
 sbin_PROGRAMS = lctl l_getidentity llverfs lustre_rsync ll_decode_linkea \
-               llsom_sync
+               llsom_sync ll_fid_path_copy
 
 if TESTS
 sbin_PROGRAMS += wiretest
@@ -82,6 +82,10 @@ lustre_rsync_SOURCES = lustre_rsync.c lustre_rsync.h callvpe.c callvpe.h
 lustre_rsync_LDADD :=  $(LIBLUSTREAPI) $(PTHREAD_LIBS)
 lustre_rsync_DEPENDENCIES := liblustreapi.la
 
+ll_fid_path_copy_SOURCES = ll_fid_path_copy.c
+ll_fid_path_copy_LDADD :=  liblustreapi.la
+ll_fid_path_copy_DEPENDENCIES := liblustreapi.la
+
 llsom_sync_LDADD := $(LIBLUSTREAPI)
 llsom_sync_DEPENDENCIES := liblustreapi.la
 
diff --git a/lustre/utils/ll_fid_path_copy.c b/lustre/utils/ll_fid_path_copy.c
new file mode 100644 (file)
index 0000000..ac96908
--- /dev/null
@@ -0,0 +1,232 @@
+#include <stdio.h>
+#include <unistd.h>
+#include <errno.h>
+#include <getopt.h>
+#include <stdlib.h>
+#include <lustre/lustreapi.h>
+#include <linux/lustre/lustre_idl.h>
+#include <sys/types.h>
+#include <sys/stat.h>
+#include <fcntl.h>
+
+void usage(void)
+{
+       printf("Usage: %s: [OPTION]...\n"
+"Copy data from a file on Lustre (specified by fid) to a file specified by path\n"
+"\n"
+"Mandatory arguments to long options are mandatory for short options too.\n"
+"  -d, --direct_io              use direct I/O\n"
+"  -F, --source_fid [fid]       fid of source file for copy\n"
+"  -h, --help                   display this help and exit\n"
+"  -l, --lustre_dir [dir]       path to a directory on Lustre\n"
+"  -p, --destination_path [path] path of destination for copy\n"
+"  -s, --iosize [size]          do reads/writes of [size] bytes, must be 1 MiB aligned\n",
+"ll_fid_path_copy");
+}
+
+size_t copy_data(int source_fd, int destination_fd, size_t iosize)
+{
+       size_t page_size = sysconf(_SC_PAGESIZE);
+       size_t total_copied = 0;
+       size_t bytes_written;
+       size_t rc2 = 0;
+       size_t rc = 0;
+       void *buf;
+
+       rc = posix_memalign(&buf, page_size, iosize);
+       if (rc != 0) {
+               fprintf(stderr, "Error: memalign failed, %lu\n", rc);
+               errno = rc;
+               goto out;
+       }
+
+       while (true) {
+               rc = read(source_fd, buf, iosize);
+               if (rc < 0) {
+                       fprintf(stderr,
+                               "Error: read from source failed, rc: %lu\n", rc);
+                       break;
+               }
+               /* copy is done */
+               if (rc == 0)
+                       break;
+               rc2 = write(destination_fd, buf, rc);
+               if (rc2 < 0) {
+                       fprintf(stderr,
+                               "Error: write to destination failed, rc: %lu\n",
+                               rc2);
+                       rc = rc2;
+                       break;
+               }
+               total_copied += rc2;
+               /* attempt the write one more time, then fail - if we're
+                * getting multiple short writes in a row, it's best to just
+                * give up so the user realizes something is wrong
+                */
+               if (rc2 < rc) { /* short write, try again */
+                       bytes_written = rc2;
+                       rc2 = write(destination_fd, buf, rc - bytes_written);
+                       if (rc2 < rc - bytes_written) {
+                               fprintf(stderr,
+                                       "Error: Retried short write, still did not complete, failing, rc: %lu\n", rc);
+                               break;
+                       }
+                       total_copied += rc2;
+               }
+       }
+
+out:
+       if (rc < 0)
+               return rc;
+       else
+               return total_copied;
+}
+
+int main(int argc, char *argv[])
+{
+       static struct option options[] = {
+               { .name = "direct_io", .has_arg = no_argument, .val = 'd', },
+               { .name = "source_fid", .has_arg = required_argument, .val = 'F', },
+               { .name = "help", .has_arg = no_argument, .val = 'h', },
+               { .name = "lustre_path", .has_arg = required_argument, .val = 'l', },
+               { .name = "destination_path", .has_arg = required_argument, .val = 'p', },
+               { .name = "iosize", .has_arg = required_argument, .val = 's', },
+       };
+       char *destination_path = NULL;
+       char *lustre_path = NULL;
+       struct lu_fid source_fid;
+       char *fidstring = NULL;
+       bool direct_io = false;
+       int extra_open_flags = 0;
+       int source_fd = -1;
+       struct stat stbuf;
+       __u32 iosize = 0;
+       size_t copied;
+       int dest_fd = -1;
+       size_t rc = 0;
+       int c;
+
+       while ((c = getopt_long(argc, argv, "dF:hl:p:s:", options, NULL)) != -1) {
+               switch (c) {
+                       case 'd':
+                               direct_io = true;
+                               break;
+                       case 'F':
+                               fidstring = optarg;
+                               break;
+                       case 'h':
+                               usage();
+                               exit(EXIT_SUCCESS);
+                               break;
+                       case 'l':
+                               lustre_path = optarg;
+                               break;
+                       case 'p':
+                               destination_path = optarg;
+                               break;
+                       case 's':
+                               iosize = strtol(optarg, NULL, 0);
+                               break;
+               }
+       }
+
+       if (!fidstring) {
+               fprintf(stderr, "Error: Must provide a source fid.\n");
+               usage();
+               exit(EXIT_FAILURE);
+       }
+
+       if (!destination_path) {
+               fprintf(stderr, "Error: Must provide destination path.\n");
+               usage();
+               exit(EXIT_FAILURE);
+       }
+
+       if (!lustre_path) {
+               fprintf(stderr, "Error: Must provide Lustre path.\n");
+               usage();
+               exit(EXIT_FAILURE);
+       }
+
+       if (iosize == 0) {
+               fprintf(stderr, "Error: Must provide iosize.\n");
+               usage();
+               exit(EXIT_FAILURE);
+       }
+
+       if (iosize % (1024 * 1024) != 0) {
+               fprintf(stderr, "Error: Iosize (%u) must be 1 MiB aligned\n",
+                       iosize);
+               usage();
+               exit(EXIT_FAILURE);
+       }
+       fprintf(stdout,
+               "Copying from %s to %s, %d bytes at a time, using %s i/o.\n",
+               fidstring, destination_path, iosize,
+               direct_io ? "direct" : "buffered");
+
+       if (direct_io)
+               extra_open_flags = O_DIRECT;
+
+       rc = llapi_fid_parse(fidstring, &source_fid, NULL);
+       if (rc < 0) {
+               fprintf(stderr, "Error: Failed to parse fid, %s\n",
+                       fidstring);
+               exit(EXIT_FAILURE);
+       }
+
+       source_fd = llapi_open_by_fid(lustre_path, &source_fid,
+                                     O_RDONLY | extra_open_flags);
+        if (source_fd < 0) {
+               perror("");
+               fprintf(stderr, "Error: Failed to open source, %s.\n",
+                       fidstring);
+               exit(EXIT_FAILURE);
+       }
+
+       rc = fstat(source_fd, &stbuf);
+       if (rc < 0) {
+               perror("");
+               fprintf(stderr, "Error: Unable to stat source, %s.\n",
+                      fidstring);
+               exit(EXIT_FAILURE);
+       }
+
+       dest_fd = open(destination_path, O_WRONLY | extra_open_flags);
+       if (dest_fd < 0) {
+               perror("");
+               fprintf(stderr, "Error: Failed to open destination, %s.\n",
+                       destination_path);
+               exit(EXIT_FAILURE);
+       }
+
+       rc = copy_data(source_fd, dest_fd, iosize);
+       if (rc < 0) {
+               /* rc is negative but errno is positive */
+               errno = -rc;
+               perror("");
+               fprintf(stderr, "Error: Failed to copy data from %s to %s.\n",
+                       fidstring, destination_path);
+               exit(EXIT_FAILURE);
+       }
+       copied = rc;
+       if (copied != stbuf.st_size) {
+               fprintf(stderr,
+                       "Error: Incomplete copy!  Only copied %lu bytes of %lu from %s to %s\n",
+                       rc, stbuf.st_size, fidstring, destination_path);
+               exit(EXIT_FAILURE);
+       }
+       rc = fstat(dest_fd, &stbuf);
+       if (copied != stbuf.st_size) {
+               fprintf(stderr,
+                       "Error: Destination size does not match bytes copied.  Copied %lu bytes, but size is %lu (copy from %s to %s)\n",
+                       rc, stbuf.st_size, fidstring, destination_path);
+               exit(EXIT_FAILURE);
+       }
+
+       fprintf(stdout,
+               "Successfully copied %lu bytes of data from %s to %s.\n",
+               copied, fidstring, destination_path);
+
+       exit(EXIT_SUCCESS);
+}
index 3f3f7ff..7a99445 100644 (file)
@@ -5771,7 +5771,7 @@ int jt_pcc_add(int argc, char **argv)
        mntpath = argv[optind++];
        pccpath = argv[optind];
 
-       snprintf(cmd, PATH_MAX, "%s %s %s", PCC_CMDNAME_ADD, pccpath, param);
+       snprintf(cmd, PATH_MAX, "%s %s %s %s", PCC_CMDNAME_ADD, pccpath, mntpath, param);
        rc = llapi_pccdev_set(mntpath, cmd);
        if (rc < 0)
                fprintf(stderr, "%s: failed to run '%s' on '%s': %s\n",