DAFS: Fix SYNC_FAILED VScheduleSalvage_r log
[openafs.git] / src / vol / volume.c
index a6560f4..65af01d 100644 (file)
@@ -22,6 +22,7 @@
 #include <afs/param.h>
 
 #include <roken.h>
+#include <afs/opr.h>
 
 #include <ctype.h>
 #include <stddef.h>
@@ -51,7 +52,7 @@
 #endif
 #endif
 #else /* AFS_VFSINCL_ENV */
-#if !defined(AFS_AIX_ENV) && !defined(AFS_LINUX20_ENV) && !defined(AFS_XBSD_ENV) && !defined(AFS_ARM_DARWIN_ENV)
+#if !defined(AFS_AIX_ENV) && !defined(AFS_LINUX20_ENV) && !defined(AFS_XBSD_ENV) && !defined(AFS_DARWIN_ENV)
 #include <sys/fs.h>
 #endif
 #endif /* AFS_VFSINCL_ENV */
 #include "partition.h"
 #include "volume_inline.h"
 #include "common.h"
-#include "afs/afs_assert.h"
 #include "vutils.h"
 #include <afs/dir.h>
 
@@ -479,6 +479,8 @@ VOptDefaults(ProgramType pt, VolumePackageOptions *opts)
     opts->interrupt_rxcall = NULL;
     opts->offline_timeout = -1;
     opts->offline_shutdown_timeout = -1;
+    opts->usage_threshold = 128;
+    opts->usage_rate_limit = 5;
 
 #ifdef FAST_RESTART
     opts->unsafe_attach = 1;
@@ -1877,6 +1879,22 @@ VShutdownVolume_r(Volume * vp)
 /* Header I/O routines                             */
 /***************************************************/
 
+static const char *
+HeaderName(bit32 magic)
+{
+    switch (magic) {
+    case VOLUMEINFOMAGIC:
+       return "volume info";
+    case SMALLINDEXMAGIC:
+       return "small index";
+    case LARGEINDEXMAGIC:
+       return "large index";
+    case LINKTABLEMAGIC:
+       return "link table";
+    }
+    return "unknown";
+}
+
 /* open a descriptor for the inode (h),
  * read in an on-disk structure into buffer (to) of size (size),
  * verify versionstamp in structure has magic (magic) and
@@ -1888,29 +1906,63 @@ ReadHeader(Error * ec, IHandle_t * h, char *to, int size, bit32 magic,
 {
     struct versionStamp *vsn;
     FdHandle_t *fdP;
+    afs_sfsize_t nbytes;
+    afs_ino_str_t stmp;
 
     *ec = 0;
     if (h == NULL) {
+       Log("ReadHeader: Null inode handle argument for %s header file.\n",
+           HeaderName(magic));
        *ec = VSALVAGE;
        return;
     }
 
     fdP = IH_OPEN(h);
     if (fdP == NULL) {
+       Log("ReadHeader: Failed to open %s header file "
+           "(volume=%u, inode=%s); errno=%d\n", HeaderName(magic), h->ih_vid,
+           PrintInode(stmp, h->ih_ino), errno);
        *ec = VSALVAGE;
        return;
     }
 
     vsn = (struct versionStamp *)to;
-    if (FDH_PREAD(fdP, to, size, 0) != size || vsn->magic != magic) {
+    nbytes = FDH_PREAD(fdP, to, size, 0);
+    if (nbytes < 0) {
+       Log("ReadHeader: Failed to read %s header file "
+           "(volume=%u, inode=%s); errno=%d\n", HeaderName(magic), h->ih_vid,
+           PrintInode(stmp, h->ih_ino), errno);
+       *ec = VSALVAGE;
+       FDH_REALLYCLOSE(fdP);
+       return;
+    }
+    if (nbytes != size) {
+       Log("ReadHeader: Incorrect number of bytes read from %s header file "
+           "(volume=%u, inode=%s); expected=%d, read=%d\n",
+           HeaderName(magic), h->ih_vid, PrintInode(stmp, h->ih_ino), size,
+           (int)nbytes);
        *ec = VSALVAGE;
        FDH_REALLYCLOSE(fdP);
        return;
     }
+    if (vsn->magic != magic) {
+       Log("ReadHeader: Incorrect magic for %s header file "
+           "(volume=%u, inode=%s); expected=0x%x, read=0x%x\n",
+           HeaderName(magic), h->ih_vid, PrintInode(stmp, h->ih_ino), magic,
+           vsn->magic);
+       *ec = VSALVAGE;
+       FDH_REALLYCLOSE(fdP);
+       return;
+    }
+
     FDH_CLOSE(fdP);
 
     /* Check is conditional, in case caller wants to inspect version himself */
     if (version && vsn->version != version) {
+       Log("ReadHeader: Incorrect version for %s header file "
+           "(volume=%u, inode=%s); expected=%x, read=%x\n",
+           HeaderName(magic), h->ih_vid, PrintInode(stmp, h->ih_ino),
+           version, vsn->version);
        *ec = VSALVAGE;
     }
 }
@@ -2147,7 +2199,8 @@ VPreAttachVolumeByVp_r(Error * ec,
         *   - volume is in an error state
         *   - volume is pre-attached
         */
-       Log("VPreattachVolumeByVp_r: volume %u not in quiescent state\n", vid);
+       Log("VPreattachVolumeByVp_r: volume %u not in quiescent state (state %u flags 0x%x)\n",
+           vid, V_attachState(vp), V_attachFlags(vp));
        goto done;
     } else if (vp) {
        /* we're re-attaching a volume; clear out some old state */
@@ -2781,7 +2834,7 @@ attach_volume_header(Error *ec, Volume *vp, struct DiskPartition64 *partp,
         SYNC_response res;
         memset(&res, 0, sizeof(res));
 
-       if (FSYNC_VolOp(volid, VPartitionPath(partp), FSYNC_VOL_NEEDVOLUME, mode, &res)
+       if (FSYNC_VolOp(volid, partp->name, FSYNC_VOL_NEEDVOLUME, mode, &res)
            != SYNC_OK) {
 
             if (res.hdr.reason == FSYNC_SALVAGE) {
@@ -2917,7 +2970,7 @@ attach_volume_header(Error *ec, Volume *vp, struct DiskPartition64 *partp,
 #if defined(AFS_DEMAND_ATTACH_FS) && defined(FSSYNC_BUILD_CLIENT)
     if (!peek && *ec == 0 && retry == 0 && VMustCheckoutVolume(mode)) {
 
-       code = FSYNC_VerifyCheckout(volid, VPartitionPath(partp), FSYNC_VOL_NEEDVOLUME, mode);
+       code = FSYNC_VerifyCheckout(volid, partp->name, FSYNC_VOL_NEEDVOLUME, mode);
 
        if (code == SYNC_DENIED) {
            /* must retry checkout; fileserver no longer thinks we have
@@ -3029,7 +3082,11 @@ attach_check_vop(Error *ec, VolumeId volid, struct DiskPartition64 *partp,
 
            /* check to see if we should set the specialStatus flag */
            if (VVolOpSetVBusy_r(vp, vp->pending_vol_op)) {
-               vp->specialStatus = VBUSY;
+               /* don't overwrite specialStatus if it was already set to
+                * something else (e.g. VMOVED) */
+               if (!vp->specialStatus) {
+                   vp->specialStatus = VBUSY;
+               }
            }
            break;
 
@@ -3108,13 +3165,18 @@ attach2(Error * ec, VolId volumeId, char *path, struct DiskPartition64 *partp,
     if (*ec == VNOVOL) {
        /* if the volume doesn't exist, skip straight to 'error' so we don't
         * request a salvage */
-       goto unlocked_error;
+       VOL_LOCK;
+       goto error_notbroken;
     }
 
     if (!*ec) {
        read_header = 1;
 
-       vp->specialStatus = (byte) (isbusy ? VBUSY : 0);
+       /* ensure that we don't override specialStatus if it was set to
+        * something else (e.g. VMOVED) */
+       if (isbusy && !vp->specialStatus) {
+           vp->specialStatus = VBUSY;
+       }
        vp->shuttingDown = 0;
        vp->goingOffline = 0;
        vp->nUsers = 1;
@@ -3192,14 +3254,14 @@ attach2(Error * ec, VolId volumeId, char *path, struct DiskPartition64 *partp,
        if (!VCanScheduleSalvage()) {
            Log("VAttachVolume: Error attaching volume %s; volume needs salvage; error=%u\n", path, *ec);
        }
-       VRequestSalvage_r(ec, vp, SALVSYNC_ERROR, VOL_SALVAGE_INVALIDATE_HEADER |
-                                                 VOL_SALVAGE_NO_OFFLINE);
+       VRequestSalvage_r(ec, vp, SALVSYNC_ERROR, VOL_SALVAGE_NO_OFFLINE);
        vp->nUsers = 0;
 
        goto locked_error;
     } else if (*ec) {
        /* volume operation in progress */
-       goto unlocked_error;
+       VOL_LOCK;
+       goto error_notbroken;
     }
 #else /* AFS_DEMAND_ATTACH_FS */
     if (*ec) {
@@ -3216,8 +3278,7 @@ attach2(Error * ec, VolId volumeId, char *path, struct DiskPartition64 *partp,
        if (!VCanScheduleSalvage()) {
            Log("VAttachVolume: volume salvage flag is ON for %s; volume needs salvage\n", path);
        }
-       VRequestSalvage_r(ec, vp, SALVSYNC_NEEDED, VOL_SALVAGE_INVALIDATE_HEADER |
-                                                  VOL_SALVAGE_NO_OFFLINE);
+       VRequestSalvage_r(ec, vp, SALVSYNC_NEEDED, VOL_SALVAGE_NO_OFFLINE);
        vp->nUsers = 0;
 
 #else /* AFS_DEMAND_ATTACH_FS */
@@ -3239,8 +3300,7 @@ attach2(Error * ec, VolId volumeId, char *path, struct DiskPartition64 *partp,
        if (!VCanScheduleSalvage()) {
            Log("VAttachVolume: volume %s needs to be salvaged; not attached.\n", path);
        }
-       VRequestSalvage_r(ec, vp, SALVSYNC_NEEDED, VOL_SALVAGE_INVALIDATE_HEADER |
-                                                  VOL_SALVAGE_NO_OFFLINE);
+       VRequestSalvage_r(ec, vp, SALVSYNC_NEEDED, VOL_SALVAGE_NO_OFFLINE);
        vp->nUsers = 0;
 
 #else /* AFS_DEMAND_ATTACH_FS */
@@ -3262,8 +3322,7 @@ attach2(Error * ec, VolId volumeId, char *path, struct DiskPartition64 *partp,
 
 #if defined(AFS_DEMAND_ATTACH_FS)
        /* schedule a salvage so the volume goes away on disk */
-       VRequestSalvage_r(ec, vp, SALVSYNC_ERROR, VOL_SALVAGE_INVALIDATE_HEADER |
-                                                 VOL_SALVAGE_NO_OFFLINE);
+       VRequestSalvage_r(ec, vp, SALVSYNC_ERROR, VOL_SALVAGE_NO_OFFLINE);
        VChangeState_r(vp, VOL_STATE_ERROR);
        vp->nUsers = 0;
        forcefree = 1;
@@ -3281,8 +3340,7 @@ attach2(Error * ec, VolId volumeId, char *path, struct DiskPartition64 *partp,
            VGetBitmap_r(ec, vp, i);
            if (*ec) {
 #ifdef AFS_DEMAND_ATTACH_FS
-               VRequestSalvage_r(ec, vp, SALVSYNC_ERROR, VOL_SALVAGE_INVALIDATE_HEADER |
-                                                         VOL_SALVAGE_NO_OFFLINE);
+               VRequestSalvage_r(ec, vp, SALVSYNC_ERROR, VOL_SALVAGE_NO_OFFLINE);
                vp->nUsers = 0;
 #endif /* AFS_DEMAND_ATTACH_FS */
                Log("VAttachVolume: error getting bitmap for volume (%s)\n",
@@ -3330,8 +3388,7 @@ attach2(Error * ec, VolId volumeId, char *path, struct DiskPartition64 *partp,
                "%lu; needs salvage\n", (int)*ec,
                afs_printable_uint32_lu(V_id(vp)));
 #ifdef AFS_DEMAND_ATTACH_FS
-           VRequestSalvage_r(ec, vp, SALVSYNC_ERROR, VOL_SALVAGE_INVALIDATE_HEADER |
-                                                     VOL_SALVAGE_NO_OFFLINE);
+           VRequestSalvage_r(ec, vp, SALVSYNC_ERROR, VOL_SALVAGE_NO_OFFLINE);
            vp->nUsers = 0;
 #else /* !AFS_DEMAND_ATTACH_FS */
            *ec = VSALVAGE;
@@ -3370,7 +3427,7 @@ attach2(Error * ec, VolId volumeId, char *path, struct DiskPartition64 *partp,
 #ifdef AFS_DEMAND_ATTACH_FS
                error_state = VOL_STATE_ERROR;
                /* see if we can recover */
-               VRequestSalvage_r(ec, vp, SALVSYNC_NEEDED, VOL_SALVAGE_INVALIDATE_HEADER);
+               VRequestSalvage_r(ec, vp, SALVSYNC_NEEDED, 0 /*flags*/);
 #endif
            }
 #ifdef AFS_DEMAND_ATTACH_FS
@@ -3403,11 +3460,18 @@ attach2(Error * ec, VolId volumeId, char *path, struct DiskPartition64 *partp,
 
     return vp;
 
+#ifndef AFS_DEMAND_ATTACH_FS
 unlocked_error:
+#endif
+
     VOL_LOCK;
 locked_error:
 #ifdef AFS_DEMAND_ATTACH_FS
     if (!VIsErrorState(V_attachState(vp))) {
+       if (VIsErrorState(error_state)) {
+           Log("attach2: forcing vol %u to error state (state %u flags 0x%x ec %d)\n",
+               vp->hashid, V_attachState(vp), V_attachFlags(vp), *ec);
+       }
        VChangeState_r(vp, error_state);
     }
 #endif /* AFS_DEMAND_ATTACH_FS */
@@ -3416,6 +3480,7 @@ locked_error:
        VReleaseVolumeHandles_r(vp);
     }
 
+ error_notbroken:
 #ifdef AFS_DEMAND_ATTACH_FS
     VCheckSalvage(vp);
     if (forcefree) {
@@ -4020,6 +4085,11 @@ GetVolume(Error * ec, Error * client_ec, VolId volumeId, Volume * hint,
        }
 
        if (V_attachState(vp) == VOL_STATE_PREATTACHED) {
+           if (vp->specialStatus) {
+               *ec = vp->specialStatus;
+               vp = NULL;
+               break;
+           }
            avp = VAttachVolumeByVp_r(ec, vp, 0);
            if (avp) {
                if (vp != avp) {
@@ -4070,9 +4140,17 @@ GetVolume(Error * ec, Error * client_ec, VolId volumeId, Volume * hint,
            vp = NULL;
            break;
        }
-#endif
 
-#ifdef AFS_DEMAND_ATTACH_FS
+       if (VIsErrorState(V_attachState(vp))) {
+           /* make sure we don't take a vp in VOL_STATE_ERROR state and use
+            * it, or transition it out of that state */
+           if (!*ec) {
+               *ec = VNOVOL;
+           }
+           vp = NULL;
+           break;
+       }
+
        /*
         * this test MUST happen after VAttachVolymeByVp, so vol_op_state is
         * not VolOpRunningUnknown (attach2 would have converted it to Online
@@ -4126,7 +4204,7 @@ GetVolume(Error * ec, Error * client_ec, VolId volumeId, Volume * hint,
                    vp->hashid);
 #ifdef AFS_DEMAND_ATTACH_FS
            if (VCanScheduleSalvage()) {
-               VRequestSalvage_r(ec, vp, SALVSYNC_ERROR, VOL_SALVAGE_INVALIDATE_HEADER);
+               VRequestSalvage_r(ec, vp, SALVSYNC_ERROR, 0 /*flags*/);
            } else {
                FreeVolume(vp);
                vp = NULL;
@@ -4311,7 +4389,7 @@ VForceOffline_r(Volume * vp, int flags)
     }
 
 #ifdef AFS_DEMAND_ATTACH_FS
-    VRequestSalvage_r(&error, vp, SALVSYNC_ERROR, VOL_SALVAGE_INVALIDATE_HEADER);
+    VRequestSalvage_r(&error, vp, SALVSYNC_ERROR, 0 /*flags*/);
 #endif /* AFS_DEMAND_ATTACH_FS */
 
 #ifdef AFS_PTHREAD_ENV
@@ -4613,11 +4691,17 @@ VDetachVolume_r(Error * ec, Volume * vp)
        notifyServer = vp->needsPutBack;
        if (V_destroyMe(vp) == DESTROY_ME)
            useDone = FSYNC_VOL_LEAVE_OFF;
-#ifdef AFS_DEMAND_ATTACH_FS
+# ifdef AFS_DEMAND_ATTACH_FS
        else if (!V_blessed(vp) || !V_inService(vp))
            useDone = FSYNC_VOL_LEAVE_OFF;
-#endif
+# endif
+    }
+# ifdef AFS_DEMAND_ATTACH_FS
+    if (V_needsSalvaged(vp)) {
+       notifyServer = 0;
+       VRequestSalvage_r(ec, vp, SALVSYNC_NEEDED, 0);
     }
+# endif
     tpartp = vp->partition;
     volume = V_id(vp);
 #endif /* FSSYNC_BUILD_CLIENT */
@@ -5460,8 +5544,8 @@ VCheckSalvage(Volume * vp)
  * @param[in]  flags   see flags note below
  *
  * @note flags:
- *       VOL_SALVAGE_INVALIDATE_HEADER causes volume header cache entry
- *                                     to be invalidated.
+ *       VOL_SALVAGE_NO_OFFLINE do not need to wait to offline the volume; it has
+ *                              not been fully attached
  *
  * @pre VOL_LOCK is held.
  *
@@ -5550,15 +5634,6 @@ VRequestSalvage_r(Error * ec, Volume * vp, int reason, int flags)
            *ec = VSALVAGE;
            code = 1;
        }
-       if (flags & VOL_SALVAGE_INVALIDATE_HEADER) {
-           /* Instead of ReleaseVolumeHeader, we do FreeVolumeHeader()
-               so that the the next VAttachVolumeByVp_r() invocation
-               of attach2() will pull in a cached header
-               entry and fail, then load a fresh one from disk and attach
-               it to the volume.
-           */
-           FreeVolumeHeader(vp);
-       }
     }
     return code;
 }
@@ -5746,7 +5821,7 @@ VScheduleSalvage_r(Volume * vp)
         * set the volume to an exclusive state and drop the lock
         * around the SALVSYNC call
         */
-       strlcpy(partName, VPartitionPath(vp->partition), sizeof(partName));
+       strlcpy(partName, vp->partition->name, sizeof(partName));
        state_save = VChangeState_r(vp, VOL_STATE_SALVSYNC_REQ);
        VOL_UNLOCK;
 
@@ -5775,6 +5850,10 @@ VScheduleSalvage_r(Volume * vp)
                Log("VScheduleSalvage_r: Salvage request for volume %lu "
                    "denied\n", afs_printable_uint32_lu(vp->hashid));
                break;
+           case SYNC_FAILED:
+               Log("VScheduleSalvage_r: Salvage request for volume %lu "
+                   "failed\n", afs_printable_uint32_lu(vp->hashid));
+               break;
            default:
                Log("VScheduleSalvage_r: Salvage request for volume %lu "
                    "received unknown protocol error %d\n",
@@ -6206,7 +6285,7 @@ VAllocBitmapEntry_r(Error * ec, Volume * vp,
                VGetBitmap_r(ec, vp, i);
                if (*ec) {
 #ifdef AFS_DEMAND_ATTACH_FS
-                   VRequestSalvage_r(ec, vp, SALVSYNC_ERROR, VOL_SALVAGE_INVALIDATE_HEADER);
+                   VRequestSalvage_r(ec, vp, SALVSYNC_ERROR, 0 /*flags*/);
 #else /* AFS_DEMAND_ATTACH_FS */
                    DeleteVolumeFromHashTable(vp);
                    vp->shuttingDown = 1;       /* Let who has it free it. */
@@ -6670,10 +6749,16 @@ VBumpVolumeUsage_r(Volume * vp)
     if (now - V_dayUseDate(vp) > OneDay)
        VAdjustVolumeStatistics_r(vp);
     /*
-     * Save the volume header image to disk after every 128 bumps to dayUse.
+     * Save the volume header image to disk after a threshold of bumps to dayUse,
+     * at most every usage_rate_limit seconds.
      */
-    if ((V_dayUse(vp)++ & 127) == 0) {
+    V_dayUse(vp)++;
+    vp->usage_bumps_outstanding++;
+    if (vp->usage_bumps_outstanding >= vol_opts.usage_threshold
+       && vp->usage_bumps_next_write <= now) {
        Error error;
+       vp->usage_bumps_outstanding = 0;
+       vp->usage_bumps_next_write = now + vol_opts.usage_rate_limit;
        VUpdateVolume_r(&error, vp, VOL_UPDATE_WAIT);
     }
 }
@@ -7901,6 +7986,51 @@ VInitVolumeHeaderCache(afs_uint32 howMany)
        ReleaseVolumeHeader(hp++);
 }
 
+/* get a volume header off of the volume header LRU.
+ *
+ * @return volume header
+ *  @retval NULL no usable volume header is available on the LRU
+ *
+ * @pre VOL_LOCK held
+ *
+ * @post for DAFS, if the returned header is associated with a volume, that
+ *       volume is NOT in an exclusive state
+ *
+ * @internal volume package internal use only.
+ */
+#ifdef AFS_DEMAND_ATTACH_FS
+static struct volHeader*
+GetVolHeaderFromLRU(void)
+{
+    struct volHeader *hd = NULL, *qh, *nqh;
+    /* Usually, a volume in an exclusive state will not have its header on
+     * the LRU. However, it is possible for this to occur when a salvage
+     * request is received over FSSYNC, and possibly in other corner cases.
+     * So just skip over headers whose volumes are in an exclusive state. We
+     * could VWaitExclusiveState_r instead, but not waiting is faster and
+     * easier to do */
+    for (queue_Scan(&volume_hdr_LRU, qh, nqh, volHeader)) {
+       if (!qh->back || !VIsExclusiveState(V_attachState(qh->back))) {
+           queue_Remove(qh);
+           hd = qh;
+           break;
+       }
+    }
+    return hd;
+}
+#else /* AFS_DEMAND_ATTACH_FS */
+static struct volHeader*
+GetVolHeaderFromLRU(void)
+{
+    struct volHeader *hd = NULL;
+    if (queue_IsNotEmpty(&volume_hdr_LRU)) {
+       hd = queue_First(&volume_hdr_LRU, volHeader);
+       queue_Remove(hd);
+    }
+    return hd;
+}
+#endif /* !AFS_DEMAND_ATTACH_FS */
+
 /**
  * get a volume header and attach it to the volume object.
  *
@@ -7969,12 +8099,8 @@ GetVolumeHeader(Volume * vp)
             V_attachFlags(vp) &= ~(VOL_HDR_IN_LRU);
 #endif
        } else {
-           /* we need to grab a new element off the LRU */
-           if (queue_IsNotEmpty(&volume_hdr_LRU)) {
-               /* grab an element and pull off of LRU */
-               hd = queue_First(&volume_hdr_LRU, volHeader);
-               queue_Remove(hd);
-           } else {
+           hd = GetVolHeaderFromLRU();
+           if (!hd) {
                /* LRU is empty, so allocate a new volHeader
                 * this is probably indicative of a leak, so let the user know */
                hd = (struct volHeader *)calloc(1, sizeof(struct volHeader));
@@ -7991,8 +8117,8 @@ GetVolumeHeader(Volume * vp)
                 * be sync'd out to disk */
 
 #ifdef AFS_DEMAND_ATTACH_FS
-               /* if hd->back were in an exclusive state, then
-                * its volHeader would not be on the LRU... */
+               /* GetVolHeaderFromLRU had better not give us back a header
+                * with a volume in exclusive state... */
                osi_Assert(!VIsExclusiveState(V_attachState(hd->back)));
 #endif
 
@@ -8730,16 +8856,14 @@ VVByPListWait_r(struct DiskPartition64 * dp)
 void
 VPrintCacheStats_r(void)
 {
-    afs_uint32 get_hi, get_lo, load_hi, load_lo;
     struct VnodeClassInfo *vcp;
     vcp = &VnodeClassInfo[vLarge];
     Log("Large vnode cache, %d entries, %d allocs, %d gets (%d reads), %d writes\n", vcp->cacheSize, vcp->allocs, vcp->gets, vcp->reads, vcp->writes);
     vcp = &VnodeClassInfo[vSmall];
     Log("Small vnode cache,%d entries, %d allocs, %d gets (%d reads), %d writes\n", vcp->cacheSize, vcp->allocs, vcp->gets, vcp->reads, vcp->writes);
-    SplitInt64(VStats.hdr_gets, get_hi, get_lo);
-    SplitInt64(VStats.hdr_loads, load_hi, load_lo);
-    Log("Volume header cache, %d entries, %d gets, %d replacements\n",
-       VStats.hdr_cache_size, get_lo, load_lo);
+    Log("Volume header cache, %d entries, %"AFS_INT64_FMT" gets, "
+        "%"AFS_INT64_FMT" replacements\n",
+       VStats.hdr_cache_size, VStats.hdr_gets, VStats.hdr_loads);
 }
 
 void