Update.

	* nscd/cache.c (cache_search): Keep track of how many chain links
	we searched and update table statistics.
	(cache_add): Keep track of how many values are in the table.
	(prune_cache): Likewise.  Keep track of locking success.
	Print messages about removed entries in separate pass.
	* nscd/connections.c (handle_request): Don't print debug message here.
	The caller will do it.  Keep track of locking success.
	(nscd_run): Print debug message.  Also print PID of the client process.
	* nscd/nscd.c (start_time): New variable.
	(main): Remember start time.
	* nscd/nscd.h: Declare start_time.
	(struct database): Add more members for new statistics.
	* nscd/nscd_stat.c: Add support for sending, receiving, and printing
	of new statistics.

5 files changed, 152 insertions, 34 deletions

diff --git a/nscd/cache.c b/nscd/cache.c
index 6492092..10b04c3c 100644
--- a/nscd/cache.c
+++ b/nscd/cache.c
@@ -44,11 +44,14 @@ cache_search (request_type type, void *key, size_t len, struct database *table,
 {
   unsigned long int hash = __nis_hash (key, len) % table->module;
   struct hashentry *work;
+  unsigned long int nsearched = 0;
 
   work = table->array[hash];
 
   while (work != NULL)
     {
+      ++nsearched;
+
       if (type == work->type && len == work->len
 	  && memcmp (key, work->key, len) == 0 && work->owner == owner)
 	{
@@ -58,13 +61,16 @@ cache_search (request_type type, void *key, size_t len, struct database *table,
 	  else
 	    ++table->poshit;
 
-	  return work;
+	  break;
 	}
 
       work = work->next;
     }
 
-  return NULL;
+  if (nsearched > table->maxnsearched)
+    table->maxnsearched = nsearched;
+
+  return work;
 }
 
 /* Add a new entry to the cache.  The return value is zero if the function
@@ -109,6 +115,12 @@ cache_add (int type, void *key, size_t len, const void *packet, size_t total,
     ++table->negmiss;
   else if (last)
     ++table->posmiss;
+
+  /* Instead of slowing down the normal process for statistics
+     collection we accept living with some incorrect data.  */
+  unsigned long int nentries = ++table->nentries;
+  if (nentries > table->maxnentries)
+    table->maxnentries = nentries;
 }
 
 /* Walk through the table and remove all entries which lifetime ended.
@@ -165,10 +177,10 @@ prune_cache (struct database *table, time_t now)
 
   /* We run through the table and find values which are not valid anymore.
 
-   Note that for the initial step, finding the entries to be removed,
-   we don't need to get any lock.  It is at all timed assured that the
-   linked lists are set up correctly and that no second thread prunes
-   the cache.  */
+     Note that for the initial step, finding the entries to be removed,
+     we don't need to get any lock.  It is at all timed assured that the
+     linked lists are set up correctly and that no second thread prunes
+     the cache.  */
   do
     {
       struct hashentry *runp = table->array[--cnt];
@@ -195,7 +207,11 @@ prune_cache (struct database *table, time_t now)
 
       /* Now we have to get the write lock since we are about to modify
 	 the table.  */
-      pthread_rwlock_wrlock (&table->lock);
+      if (__builtin_expect (pthread_rwlock_trywrlock (&table->lock) != 0, 0))
+	{
+	  ++table->wrlockdelayed;
+	  pthread_rwlock_wrlock (&table->lock);
+	}
 
       while (first <= last)
 	{
@@ -208,6 +224,7 @@ prune_cache (struct database *table, time_t now)
 		  table->array[first]->dellist = head;
 		  head = table->array[first];
 		  table->array[first] = head->next;
+		  --table->nentries;
 		  if (--mark[first] == 0)
 		    break;
 		}
@@ -221,6 +238,7 @@ prune_cache (struct database *table, time_t now)
 		      head = runp->next;
 		      runp->next = head->next;
 		      --mark[first];
+		      --table->nentries;
 		    }
 		  else
 		    runp = runp->next;
@@ -232,29 +250,35 @@ prune_cache (struct database *table, time_t now)
       /* It's all done.  */
       pthread_rwlock_unlock (&table->lock);
 
-      /* And another run to free the data.  */
-      do
+      /* One extra pass if we do debugging.  */
+      if (__builtin_expect (debug_level > 0, 0))
 	{
-	  struct hashentry *old = head;
+	  struct hashentry *runp = head;
 
-	  if (debug_level > 0)
+	  while (runp != NULL)
 	    {
 	      char buf[INET6_ADDRSTRLEN];
 	      const char *str;
 
-	      if ((old->type == GETHOSTBYADDR || old->type == GETHOSTBYADDRv6)
-		  && (old->last || old->data == (void *) -1))
+	      if (runp->type == GETHOSTBYADDR || runp->type == GETHOSTBYADDRv6)
 		{
-		  inet_ntop (old->type == GETHOSTBYADDR ? AF_INET : AF_INET6,
-			     old->key, buf, sizeof (buf));
+		  inet_ntop (runp->type == GETHOSTBYADDR ? AF_INET : AF_INET6,
+			     runp->key, buf, sizeof (buf));
 		  str = buf;
 		}
 	      else
-		str = old->last ? old->key : (old->data == (void *) -1
-					      ? old->key : "???");
+		str = runp->key;
 
-	      dbg_log ("remove %s entry \"%s\"", serv2str[old->type], str);
+	      dbg_log ("remove %s entry \"%s\"", serv2str[runp->type], str);
+
+	      runp = runp->next;
 	    }
+	}
+
+      /* And another run to free the data.  */
+      do
+	{
+	  struct hashentry *old = head;
 
 	  /* Free the data structures.  */
 	  if (old->data == (void *) -1)
diff --git a/nscd/connections.c b/nscd/connections.c
index 2e87269..3628877 100644
--- a/nscd/connections.c
+++ b/nscd/connections.c
@@ -256,10 +256,6 @@ invalidate_cache (char *key)
 static void
 handle_request (int fd, request_header *req, void *key, uid_t uid)
 {
-  if (__builtin_expect (debug_level, 0) > 0)
-    dbg_log (_("handle_request: request received (Version = %d)"),
-	     req->version);
-
   if (__builtin_expect (req->version, NSCD_VERSION) != NSCD_VERSION)
     {
       if (debug_level > 0)
@@ -309,7 +305,11 @@ cannot handle old request version %d; current version is %d"),
 	}
 
       /* Be sure we can read the data.  */
-      pthread_rwlock_rdlock (&db->lock);
+      if (__builtin_expect (pthread_rwlock_tryrdlock (&db->lock) != 0, 0))
+	{
+	  ++db->rdlockdelayed;
+	  pthread_rwlock_rdlock (&db->lock);
+	}
 
       /* See whether we can handle it from the cache.  */
       cached = (struct hashentry *) cache_search (req->type, key, req->key_len,
@@ -465,6 +465,9 @@ nscd_run (void *p)
 	  request_header req;
 	  char buf[256];
 	  uid_t uid = 0;
+#ifdef SO_PEERCRED
+	  pid_t pid = 0;
+#endif
 
 	  if (__builtin_expect (fd, 0) < 0)
 	    {
@@ -505,6 +508,17 @@ nscd_run (void *p)
 	      if (req.type < GETPWBYNAME || req.type > LASTDBREQ
 		  || secure[serv2db[req.type]])
 		uid = caller.uid;
+
+	      pid = caller.pid;
+	    }
+	  else if (__builtin_expect (debug_level > 0, 0))
+	    {
+	      struct ucred caller;
+	      socklen_t optlen = sizeof (caller);
+
+	      if (getsockopt (fd, SOL_SOCKET, SO_PEERCRED,
+			      &caller, &optlen) == 0)
+		pid = caller.pid;
 	    }
 #endif
 
@@ -535,6 +549,19 @@ nscd_run (void *p)
 		  continue;
 		}
 
+	      if (__builtin_expect (debug_level, 0) > 0)
+		{
+#ifdef SO_PEERCRED
+		  if (pid != 0)
+		    dbg_log (_("\
+handle_request: request received (Version = %d) from PID %ld"),
+			     req.version, (long int) pid);
+		  else
+#endif
+		    dbg_log (_("\
+handle_request: request received (Version = %d)"), req.version);
+		}
+
 	      /* Phew, we got all the data, now process it.  */
 	      handle_request (fd, &req, keybuf, uid);
 
diff --git a/nscd/nscd.c b/nscd/nscd.c
index 5844b38..3d55741 100644
--- a/nscd/nscd.c
+++ b/nscd/nscd.c
@@ -72,6 +72,8 @@ int secure[lastdb];
 int secure_in_use;
 static const char *conffile = _PATH_NSCDCONF;
 
+time_t start_time;
+
 static int check_pid (const char *file);
 static int write_pid (const char *file);
 
@@ -131,6 +133,9 @@ main (int argc, char **argv)
   if (check_pid (_PATH_NSCDPID))
     error (EXIT_FAILURE, 0, _("already running"));
 
+  /* Remember when we started.  */
+  start_time = time (NULL);
+
   /* Behave like a daemon.  */
   if (go_background)
     {
diff --git a/nscd/nscd.h b/nscd/nscd.h
index f500b15..89ac777 100644
--- a/nscd/nscd.h
+++ b/nscd/nscd.h
@@ -77,6 +77,13 @@ struct database
   unsigned long int posmiss;
   unsigned long int negmiss;
 
+  unsigned long int nentries;
+  unsigned long int maxnentries;
+  unsigned long int maxnsearched;
+
+  unsigned long int rdlockdelayed;
+  unsigned long int wrlockdelayed;
+
   struct hashentry **array;
 };
 
@@ -99,6 +106,9 @@ extern int secure_in_use; /* Is one of the above 1 ? */
 /* User name to run server processes as */
 extern const char *server_user;
 
+/* Time the server was started.  */
+extern time_t start_time;
+
 /* Prototypes for global functions.  */
 
 /* nscd.c */
diff --git a/nscd/nscd_stat.c b/nscd/nscd_stat.c
index 2d46278..d55ca74 100644
--- a/nscd/nscd_stat.c
+++ b/nscd/nscd_stat.c
@@ -1,4 +1,4 @@
-/* Copyright (c) 1998 Free Software Foundation, Inc.
+/* Copyright (c) 1998, 2003 Free Software Foundation, Inc.
    This file is part of the GNU C Library.
    Contributed by Thorsten Kukuk <kukuk@vt.uni-paderborn.de>, 1998.
 
@@ -46,6 +46,13 @@ struct dbstat
   unsigned long int neghit;
   unsigned long int posmiss;
   unsigned long int negmiss;
+
+  unsigned long int nentries;
+  unsigned long int maxnentries;
+  unsigned long int maxnsearched;
+
+  unsigned long int rdlockdelayed;
+  unsigned long int wrlockdelayed;
 };
 
 /* Record for transmitting statistics.  */
@@ -53,6 +60,7 @@ struct statdata
 {
   char version[sizeof (compilation)];
   int debug_level;
+  time_t runtime;
   int ndbs;
   struct dbstat dbs[lastdb];
 };
@@ -66,6 +74,7 @@ send_stats (int fd, struct database dbs[lastdb])
 
   memcpy (data.version, compilation, sizeof (compilation));
   data.debug_level = debug_level;
+  data.runtime = time (NULL) - start_time;
   data.ndbs = lastdb;
 
   for (cnt = 0; cnt < lastdb; ++cnt)
@@ -79,6 +88,11 @@ send_stats (int fd, struct database dbs[lastdb])
       data.dbs[cnt].neghit = dbs[cnt].neghit;
       data.dbs[cnt].posmiss = dbs[cnt].posmiss;
       data.dbs[cnt].negmiss = dbs[cnt].negmiss;
+      data.dbs[cnt].nentries = dbs[cnt].nentries;
+      data.dbs[cnt].maxnentries = dbs[cnt].maxnentries;
+      data.dbs[cnt].maxnsearched = dbs[cnt].maxnsearched;
+      data.dbs[cnt].rdlockdelayed = dbs[cnt].rdlockdelayed;
+      data.dbs[cnt].wrlockdelayed = dbs[cnt].wrlockdelayed;
     }
 
   if (TEMP_FAILURE_RETRY (write (fd, &data, sizeof (data))) != sizeof (data))
@@ -120,7 +134,7 @@ receive_print_stats (void)
   if (TEMP_FAILURE_RETRY (read (fd, &data, sizeof (data))) != sizeof (data)
       || (memcmp (data.version, compilation, sizeof (compilation)) != 0
 	  /* Yes, this is an assignment!  */
-	  && errno == EINVAL))
+	  && (errno = EINVAL)))
     {
       /* Not the right version.  */
       int err = errno;
@@ -131,6 +145,36 @@ receive_print_stats (void)
   printf (_("nscd configuration:\n\n%15d  server debug level\n"),
 	  data.debug_level);
 
+  /* We know that we can simply subtract time_t values.  */
+  unsigned long int diff = data.runtime;
+  unsigned int ndays = 0;
+  unsigned int nhours = 0;
+  unsigned int nmins = 0;
+  if (diff > 24 * 60 * 60)
+    {
+      ndays = diff / (24 * 60 * 60);
+      diff %= 24 * 60 * 60;
+    }
+  if (diff > 60 * 60)
+    {
+      nhours = diff / (60 * 60);
+      diff %= 60 * 60;
+    }
+  if (diff > 60)
+    {
+      nmins = diff / 60;
+      diff %= 60;
+    }
+  if (ndays != 0)
+    printf (_("%3ud %2uh %2um %2lus  server runtime\n"),
+	    ndays, nhours, nmins, diff);
+  else if (nhours != 0)
+    printf (_("    %2uh %2um %2lus  server runtime\n"), nhours, nmins, diff);
+  else if (nmins != 0)
+    printf (_("        %2um %2lus  server runtime\n"), nmins, diff);
+  else
+    printf (_("            %2lus  server runtime\n"), diff);
+
   for (i = 0; i < lastdb; ++i)
     {
       unsigned long int hit = data.dbs[i].poshit + data.dbs[i].neghit;
@@ -153,14 +197,19 @@ receive_print_stats (void)
 
       printf (_("\n%s cache:\n\n"
 		"%15s  cache is enabled\n"
-		"%15Zd  suggested size\n"
-		"%15ld  seconds time to live for positive entries\n"
-		"%15ld  seconds time to live for negative entries\n"
-		"%15ld  cache hits on positive entries\n"
-		"%15ld  cache hits on negative entries\n"
-		"%15ld  cache misses on positive entries\n"
-		"%15ld  cache misses on negative entries\n"
-		"%15ld%% cache hit rate\n"
+		"%15Zu  suggested size\n"
+		"%15lu  seconds time to live for positive entries\n"
+		"%15lu  seconds time to live for negative entries\n"
+		"%15lu  cache hits on positive entries\n"
+		"%15lu  cache hits on negative entries\n"
+		"%15lu  cache misses on positive entries\n"
+		"%15lu  cache misses on negative entries\n"
+		"%15lu%% cache hit rate\n"
+		"%15lu  current number of cached values\n"
+		"%15lu  maximum number of cached values\n"
+		"%15lu  maximum chain length searched\n"
+		"%15lu  number of delays on rdlock\n"
+		"%15lu  number of delays on wrlock\n"
 		"%15s  check /etc/%s for changes\n"),
 	      dbnames[i], enabled,
 	      data.dbs[i].module,
@@ -168,7 +217,10 @@ receive_print_stats (void)
 	      data.dbs[i].poshit, data.dbs[i].neghit,
 	      data.dbs[i].posmiss, data.dbs[i].negmiss,
 	      (100 * hit) / all,
-	      check_file, dbnames[i]);
+	      data.dbs[i].nentries, data.dbs[i].maxnentries,
+	      data.dbs[i].maxnsearched,
+	      data.dbs[i].rdlockdelayed,
+	      data.dbs[i].wrlockdelayed, check_file, dbnames[i]);
     }
 
   close (fd);