afs: Log warning when we detect too many vcaches

Currently, afs_ShakeLooseVCaches has a kind of warning that is logged
when we fail to free up any vcaches. This information can be useful to
know, since it may be a sign that users are trying to access way more
files than our configured vcache limit, hindering performance as we
constantly try to evict and re-create vcaches for files.

However, the current warning is not clear at all to non-expert users,
and it can only occur for non-dynamic vcaches (which is uncommon these
days).

To improve this, try to make a general determination if it looks like
the stat cache is "stressed", and log a message if so after
afs_ShakeLooseVCaches runs (for all platforms, regardless of dynamic
vcaches). Also try to make the message a little more user-friendly,
and only log it (at most) once per 4 hours.

Determining whether the stat cache looks stressed or not is difficult
and arguably subjective (especially for dynamic vcaches). This commit
draws a few arbitrary lines in the sand to make the decision, so at
least something will be logged in the cases where users are constantly
accessing way more files than our configured vcache limit.

Change-Id: I022478dc8abb7fdef24ccc06d477b349cca759ac
Reviewed-on: https://gerrit.openafs.org/13255
Reviewed-by: Cheyenne Wills <cwills@sinenomine.net>
Tested-by: BuildBot <buildbot@rampaginggeek.com>
Reviewed-by: Benjamin Kaduk <kaduk@mit.edu>

diff --git a/src/afs/afs.h b/src/afs/afs.h
index e205adb..8d9dd67 100644 (file)
--- a/src/afs/afs.h
+++ b/src/afs/afs.h
@@ -104,6 +104,8 @@ extern enum afs_shutdown_state afs_shuttingdown;
 
 #define AFS_MAXCBRSCALL        32      /* max to return in a given call (must be <= AFSCBMAX) */
 #define        VCACHE_FREE     5
+#define VCACHE_DYNAMIC_STRESSED 10000
+#define VCACHE_STRESS_LOGINTERVAL (60*60*4) /* 4 hours */
 #define        AFS_NRXPACKETS  80
 #define        AFS_RXDEADTIME  50
 #define AFS_HARDDEADTIME       120

diff --git a/src/afs/afs_prototypes.h b/src/afs/afs_prototypes.h
index d8132ff..6a95be1 100644 (file)
--- a/src/afs/afs_prototypes.h
+++ b/src/afs/afs_prototypes.h
@@ -1044,6 +1044,7 @@ extern void afs_WarnENOSPC(void);
 /* afs_vcache.c */
 extern int VCHash(struct VenusFid *fid);
 extern int VCHashV(struct VenusFid *fid);
+extern int afs_VCacheStressed(void);
 extern int afs_ShakeLooseVCaches(afs_int32 anumber);
 extern afs_int32 afs_maxvcount;
 extern afs_int32 afs_vcount;

diff --git a/src/afs/afs_vcache.c b/src/afs/afs_vcache.c
index 7ae4723..160b011 100644 (file)
--- a/src/afs/afs_vcache.c
+++ b/src/afs/afs_vcache.c
@@ -746,6 +746,56 @@ afs_PostPopulateVCache(struct vcache *avc, struct VenusFid *afid, int seq)
     afs_osi_Wakeup(&avc->f.states);
 }
 
+/*
+ * afs_VCacheStressed() is intended to determine if the stat cache looks
+ * stressed / full-ish. Due to the different strategies of allocating vcaches
+ * on different platforms, the definition of "stressed" varies, and is somewhat
+ * arbitrary. We just try to make a reasonable guess here.
+ *
+ * Returns 1 if the stat cache looks stressed, and 0 otherwise.
+ */
+#ifdef AFS_LINUX26_ENV
+int
+afs_VCacheStressed(void)
+{
+    if (afsd_dynamic_vcaches) {
+       /*
+        * For dynamic vcaches, the number of vcaches in use can vary wildly.
+        * Consider us stressed if we're significantly above the configured
+        * threshold. VCACHE_DYNAMIC_STRESSED is the arbitrary point at which
+        * we're considered "significantly" over the threshold.
+        */
+       if (afs_vcount > afs_cacheStats + VCACHE_DYNAMIC_STRESSED) {
+           return 1;
+       }
+       return 0;
+
+    } else {
+       /*
+        * For non-dynamic vcaches, we should never go above the configured
+        * limit, and ShakeLooseVCaches should try to get us to VCACHE_FREE
+        * under the limit. So if we're closer then VCACHE_FREE/2, then we're
+        * very close to the limit, so consider us stressed.
+        */
+       if (afs_vcount > afs_cacheStats || afs_cacheStats - afs_vcount < VCACHE_FREE/2) {
+           return 1;
+       }
+       return 0;
+    }
+}
+#else /* AFS_LINUX26_ENV */
+int
+afs_VCacheStressed(void)
+{
+    /* If we don't have any vcaches in the free list, then consider the stat
+     * cache stressed. */
+    if (freeVCList != NULL) {
+       return 0;
+    }
+    return 1;
+}
+#endif /* AFS_LINUX26_ENV */
+
 int
 afs_ShakeLooseVCaches(afs_int32 anumber)
 {
@@ -755,7 +805,6 @@ afs_ShakeLooseVCaches(afs_int32 anumber)
     struct afs_q *tq, *uq;
     int fv_slept, defersleep = 0;
     int limit;
-    afs_int32 target = anumber;
 
     loop = 0;
 
@@ -805,9 +854,27 @@ afs_ShakeLooseVCaches(afs_int32 anumber)
            break;
        }
     }
-    if (!afsd_dynamic_vcaches && anumber == target) {
-       afs_warn("afs_ShakeLooseVCaches: warning none freed, using %d of %d\n",
-              afs_vcount, afs_maxvcount);
+
+    if (afs_VCacheStressed()) {
+       /*
+        * If it looks like we have too many vcaches, right after
+        * ShakeLooseVCaches has tried to trim down the number of vcaches, then
+        * maybe -stat should be increased. Log a warning, so if this is
+        * causing problems the user has a chance at noticing.
+        */
+       static afs_uint32 last_warned;
+       afs_uint32 now = osi_Time();
+
+       /* Warn about this at most once every VCACHE_STRESS_LOGINTERVAL secs */
+       if (now - last_warned > VCACHE_STRESS_LOGINTERVAL) {
+           last_warned = now;
+           afs_warn("afs: Warning: We are having trouble keeping the AFS stat "
+                    "cache trimmed down under the configured limit (current "
+                    "-stat setting: %d, current vcache usage: %d).\n",
+                    afs_cacheStats, afs_vcount);
+           afs_warn("afs: If AFS access seems slow, consider raising the "
+                    "-stat setting for afsd.\n");
+       }
     }
 
     return 0;