INN commit: trunk (6 files)

INN Commit rra at isc.org
Tue Mar 16 19:30:43 UTC 2010


    Date: Tuesday, March 16, 2010 @ 12:30:42
  Author: iulius
Revision: 9002

Change how innd logs its article counts.  A checkpoint is added
just before a connection is closed.  Checkpoints contain values
accumulated since the last checkpoint.
This way, innreport can rely on checkpoints only, so as to produce
more accurate stats.

see #7

Modified:
  trunk/doc/pod/news.pod
  trunk/innd/chan.c
  trunk/innd/innd.h
  trunk/innd/nc.c
  trunk/innd/rc.c
  trunk/scripts/innreport_inn.pm

--------------------------+
 doc/pod/news.pod         |    9 ++++
 innd/chan.c              |   14 ++++++-
 innd/innd.h              |   26 +++++++++----
 innd/nc.c                |   20 +++++++++-
 innd/rc.c                |    2 +
 scripts/innreport_inn.pm |   85 ++++++---------------------------------------
 6 files changed, 70 insertions(+), 86 deletions(-)

Modified: doc/pod/news.pod
===================================================================
--- doc/pod/news.pod	2010-03-14 21:04:23 UTC (rev 9001)
+++ doc/pod/news.pod	2010-03-16 19:30:42 UTC (rev 9002)
@@ -324,6 +324,15 @@
 
 =item *
 
+Changed how B<innreport> takes into account B<innd> and B<innfeed> checkpoint
+messages.  Previously, the fact that connections can be open for days led
+to produce skewed numbers on how many articles had been received or sent.
+The count is now more accurate and, for each connection of a feed, only
+depends on I<incominglogfrequency> in F<inn.conf> and I<stats-period>
+in F<innfeed.conf>.
+
+=item *
+
 Fixed a bug in B<nnrpd> Perl filter:  a header field whose name begins with
 the name of a standardized header field was not properly taken into account.
 

Modified: innd/chan.c
===================================================================
--- innd/chan.c	2010-03-14 21:04:23 UTC (rev 9001)
+++ innd/chan.c	2010-03-16 19:30:42 UTC (rev 9002)
@@ -195,6 +195,7 @@
     cp->Reader = reader;
     cp->WriteDone = write_done;
     cp->Started = Now.tv_sec;
+    cp->Started_checkpoint = Now.tv_sec;
     cp->LastActive = Now.tv_sec;
     cp->In = in;
     cp->Out = out;
@@ -286,6 +287,17 @@
         notice("%s closed seconds %ld cancels %ld", name,
                (long)(Now.tv_sec - cp->Started), cp->Received);
     else {
+        notice("%s checkpoint seconds %ld accepted %ld refused %ld rejected %ld"
+               " duplicate %ld accepted size %.0f duplicate size %.0f"
+               " rejected size %.0f", name,
+               (long)(Now.tv_sec - cp->Started_checkpoint),
+               cp->Received - cp->Received_checkpoint,
+               cp->Refused - cp->Refused_checkpoint,
+               cp->Rejected - cp->Rejected_checkpoint,
+               cp->Duplicate - cp->Duplicate_checkpoint,
+               cp->Size - cp->Size_checkpoint,
+               cp->DuplicateSize - cp->DuplicateSize_checkpoint,
+               cp->RejectSize - cp->RejectSize_checkpoint);
         notice("%s closed seconds %ld accepted %ld refused %ld rejected %ld"
                " duplicate %ld accepted size %.0f duplicate size %.0f"
                " rejected size %.0f", name, (long)(Now.tv_sec - cp->Started),
@@ -376,7 +388,7 @@
         if (cp->Type == CTnntp)
             CHANclose_nntp(cp, name);
         else if (cp->Type == CTreject)
-            notice("%s %ld", name, cp->Rejected);
+            notice("%s %ld", name, cp->Rejected); /* Use cp->Rejected for the response code. */
         else if (cp->Out.left)
             warn("%s closed lost %lu", name, (unsigned long) cp->Out.left);
         else

Modified: innd/innd.h
===================================================================
--- innd/innd.h	2010-03-14 21:04:23 UTC (rev 9001)
+++ innd/innd.h	2010-03-16 19:30:42 UTC (rev 9002)
@@ -339,16 +339,20 @@
   bool                 CanAuthenticate; /* Can use AUTHINFO? */
   bool                 IsAuthenticated; /* No need to use AUTHINFO? */
   bool                 HasSentUsername; /* Has used AUTHINFO USER? */
-  unsigned long	       Duplicate;
+  unsigned long        Duplicate;
+  unsigned long        Duplicate_checkpoint;
   unsigned long	       Unwanted_s;
   unsigned long	       Unwanted_f;
   unsigned long	       Unwanted_d;
   unsigned long	       Unwanted_g;
   unsigned long	       Unwanted_u;
   unsigned long	       Unwanted_o;
-  float		       Size;
-  float		       DuplicateSize;
-  float		       RejectSize;
+  float                Size;
+  float                Size_checkpoint;
+  float                DuplicateSize;
+  float                DuplicateSize_checkpoint;
+  float                RejectSize;
+  float                RejectSize_checkpoint;
   unsigned long	       Check;
   unsigned long	       Check_send;
   unsigned long	       Check_deferred;
@@ -363,20 +367,24 @@
   unsigned long	       Ihave_SendIt;
   unsigned long	       Ihave_Cybercan;
   unsigned long        Reported;
-  long		       Received;
-  long		       Refused;
-  long		       Rejected;
+  unsigned long        Received;
+  unsigned long        Received_checkpoint;
+  unsigned long        Refused;
+  unsigned long        Refused_checkpoint;
+  unsigned long        Rejected;
+  unsigned long        Rejected_checkpoint;
   unsigned long        BadWrites;
   unsigned long        BadReads;
   unsigned long        BlockedWrites;
-  int		       BadCommands;
+  unsigned int         BadCommands;
   time_t	       LastActive;
   time_t	       NextLog;
   struct sockaddr_storage Address;
   innd_callback_func   Reader;
   innd_callback_func   WriteDone;
   time_t	       Waketime;
-  time_t	       Started;
+  time_t               Started;
+  time_t               Started_checkpoint;
   innd_callback_func   Waker;
   void		    *  Argument;
   void		    *  Event;

Modified: innd/nc.c
===================================================================
--- innd/nc.c	2010-03-14 21:04:23 UTC (rev 9001)
+++ innd/nc.c	2010-03-16 19:30:42 UTC (rev 9002)
@@ -274,10 +274,24 @@
     syslog(L_NOTICE,
            "%s checkpoint seconds %ld accepted %ld refused %ld rejected %ld duplicate %ld"
            " accepted size %.0f duplicate size %.0f rejected size %.0f",
-           CHANname(cp), (long)(Now.tv_sec - cp->Started),
-           cp->Received, cp->Refused, cp->Rejected,
-           cp->Duplicate, cp->Size, cp->DuplicateSize, cp->RejectSize);
+           CHANname(cp),
+           (long)(Now.tv_sec - cp->Started_checkpoint),
+           cp->Received - cp->Received_checkpoint,
+           cp->Refused - cp->Refused_checkpoint,
+           cp->Rejected - cp->Rejected_checkpoint,
+           cp->Duplicate - cp->Duplicate_checkpoint,
+           cp->Size - cp->Size_checkpoint,
+           cp->DuplicateSize - cp->DuplicateSize_checkpoint,
+           cp->RejectSize - cp->RejectSize_checkpoint);
     cp->Reported = 0;
+    cp->Started_checkpoint = Now.tv_sec;
+    cp->Received_checkpoint = cp->Received;
+    cp->Refused_checkpoint = cp->Refused;
+    cp->Rejected_checkpoint = cp->Rejected;
+    cp->Duplicate_checkpoint = cp->Duplicate;
+    cp->Size_checkpoint = cp->Size;
+    cp->DuplicateSize_checkpoint = cp->DuplicateSize;
+    cp->RejectSize_checkpoint = cp->RejectSize;
   }
 
   cp->State = CSgetcmd;

Modified: innd/rc.c
===================================================================
--- innd/rc.c	2010-03-14 21:04:23 UTC (rev 9001)
+++ innd/rc.c	2010-03-16 19:30:42 UTC (rev 9002)
@@ -540,6 +540,7 @@
 	    RCrejectwritedone);
 	memcpy(&remotetable[i].Address, &remote,
                sizeof(remotetable[i].Address));
+        /* Use cp->Rejected for the response code in CHANclose. */
 	new->Rejected = reject_val;
 	RCHANremove(new);
 	WCHANset(new, reject_message, (int)strlen(reject_message));
@@ -612,6 +613,7 @@
         new = CHANcreate(fd, CTreject, CSwritegoodbye, RCrejectreader,
             RCrejectwritedone);
 	memcpy(&new->Address, &remote, sizeof(new->Address));
+        /* Use cp->Rejected for the response code in CHANclose. */
         new->Rejected = reject_val;
         RCHANremove(new);
         WCHANset(new, reject_message, (int)strlen(reject_message));

Modified: scripts/innreport_inn.pm
===================================================================
--- scripts/innreport_inn.pm	2010-03-14 21:04:23 UTC (rev 9001)
+++ scripts/innreport_inn.pm	2010-03-16 19:30:42 UTC (rev 9002)
@@ -309,16 +309,6 @@
 }
 $nnrpd_time_times = 0;        # ...
 
-my %notice_state;
-my %notice_state_ever_closed;
-my %innd_cp_accepted;
-my %innd_cp_refused;
-my %innd_cp_rejected;
-my %innd_cp_seconds;
-my %innd_cp_stored_size;
-my %innd_cp_duplicated_size;
-my %innd_cp_rejected_size;
-
 # collect: Used to collect the data.
 sub collect($$$$$$) {
   my ($day, $hour, $prog, $res, $left, $CASE_SENSITIVE) = @_;
@@ -591,64 +581,25 @@
 
     # closed/checkpoint (with times)
     #
-    # For checkpoints, store the current checkpoint numbers; if we still have
-    # checkpoint numbers left over at the end of the run, we'll add them to
-    # our totals.  On a closed, clear any checkpoint numbers and add the close
-    # numbers to the totals.  Basically, we want to ignore checkpoints unless
-    # we don't get a close before the end of the log.
+    # Add all checkpoints.  They contain stats generated since the last
+    # checkpoint.
+    # On a closed, a checkpoint is generated by innd.  It is therefore
+    # useless to take into account a line corresponding to a closed status.
     if ($left =~ /(\S+:\d+) (checkpoint|closed) seconds (\d+) accepted (\d+) refused (\d+) rejected (\d+) duplicate (\d+) accepted size (\d+) duplicate size (\d+)(?: rejected size (\d+))?$/o) {
       my ($server, $status, $seconds, $accepted, $refused, $rejected, $duplicate, $accptsize, $dupsize, $rjctsize) =
 	($1, $2, $3, $4, $5, $6, $7, $8, $9, $10);
       $server = lc $server unless $CASE_SENSITIVE;
-      $notice_state{$server} = $status;
 
       if ($status eq 'checkpoint') {
-        $innd_cp_accepted{$server}        = $accepted;
-        $innd_cp_refused{$server}         = $refused;
-        $innd_cp_rejected{$server}        = $rejected;
-        $innd_cp_seconds{$server}         = $seconds;
-        $innd_cp_stored_size{$server}     = $accptsize;
-        $innd_cp_duplicated_size{$server} = $dupsize;
-        $innd_cp_rejected_size{$server}   = ($rjctsize || 0);
-      } elsif ($status eq "closed") {
-        $innd_cp_accepted{$server}        = 0;
-        $innd_cp_refused{$server}         = 0;
-        $innd_cp_rejected{$server}        = 0;
-        $innd_cp_seconds{$server}         = 0;
-        $innd_cp_stored_size{$server}     = 0;
-        $innd_cp_duplicated_size{$server} = 0;
-        $innd_cp_rejected_size{$server}   = 0;
-
-        $notice_state_ever_closed{$server} = "YES";
-
-        $innd_seconds{$server} += $seconds;
-        $innd_accepted{$server} += $accepted;
-        $innd_refused{$server} += $refused;
-        $innd_rejected{$server} += $rejected;
-        $innd_stored_size{$server} += $accptsize;
+        $innd_seconds{$server}         += $seconds;
+        $innd_accepted{$server}        += $accepted;
+        $innd_refused{$server}         += $refused;
+        $innd_rejected{$server}        += $rejected;
+        $innd_stored_size{$server}     += $accptsize;
         $innd_duplicated_size{$server} += $dupsize;
-        $innd_rejected_size{$server} += ($rjctsize || 0);
+        $innd_rejected_size{$server}   += ($rjctsize || 0);
       }
       return 1;
-    # closed (with times)
-    } elsif ($left =~ /(\S+:\d+) closed seconds (\d+) accepted (\d+) refused (\d+) rejected (\d+)$/o) {
-      my ($server, $seconds, $accepted, $refused, $rejected) =
-	($1, $2, $3, $4, $5);
-      $server = lc $server unless $CASE_SENSITIVE;
-
-      $innd_cp_accepted{$server}        = 0;
-      $innd_cp_refused{$server}         = 0;
-      $innd_cp_rejected{$server}        = 0;
-      $innd_cp_seconds{$server}         = 0;
-      $innd_cp_stored_size{$server}     = 0;
-      $innd_cp_duplicated_size{$server} = 0;
-      $innd_cp_rejected_size{$server}   = 0;
-
-      $innd_seconds{$server} += $seconds;
-      $innd_accepted{$server} += $accepted;
-      $innd_refused{$server} += $refused;
-      $innd_rejected{$server} += $rejected;
-      return 1;
     }
     # closed (without times (?))
     return 1 if $left =~ m/\S+ closed$/o;
@@ -2155,27 +2106,15 @@
   {
     my ($key, $hostname, $channel);
 
-    # If there are any checkpoint counts left over at the end of the file,
-    # transfer them to the totals for that server.
-    #
-    # Also, since the checkpoint counts include entries for all server
+    # Since the checkpoint counts include entries for all server
     # connections, check to see if any checkpoint server entries are not also
     # in %innd_connect.  Add any missing servers (persistant servers with no
     # connected log lines) to %innd_connect so that incoming totals will be
     # properly computed.
-    foreach $server (keys (%innd_cp_accepted)) {
+    foreach $server (keys (%innd_accepted)) {
       if (! defined($innd_connect{$server})) {
         $innd_connect{$server} = 0;
       }
-      if ($notice_state{$server} eq "checkpoint") {
-        $innd_accepted{$server}        += $innd_cp_accepted{$server};
-        $innd_refused{$server}         += $innd_cp_refused{$server};
-        $innd_rejected{$server}        += $innd_cp_rejected{$server};
-        $innd_seconds{$server}         += $innd_cp_seconds{$server};
-        $innd_stored_size{$server}     += $innd_cp_stored_size{$server};
-        $innd_duplicated_size{$server} += $innd_cp_duplicated_size{$server};
-        $innd_rejected_size{$server}   += ($innd_cp_rejected_size{$server} || 0);
-      }
     }
 
     foreach $key (keys (%innd_connect)) {




More information about the inn-committers mailing list