reconnect: Track last-disconnected time.
authorAndrew Evans <aevans@nicira.com>
Thu, 10 Mar 2011 02:36:26 +0000 (18:36 -0800)
committerAndrew Evans <aevans@nicira.com>
Thu, 10 Mar 2011 02:40:03 +0000 (18:40 -0800)
Commit a4613b01ab (ovsdb: Change the way connection duration time is reported
in Manager table.), pushed earlier today, requires this commit, so OVSDB has
been unbuildable from then to now.

lib/reconnect.c
lib/reconnect.h
python/ovs/reconnect.py
tests/reconnect.at
tests/test-reconnect.c
tests/test-reconnect.py

index d7357c2025c7a4897c78bac882cc393090d90ce2..08ce858647fb6a039e80c615969fc984ecb5bbec 100644 (file)
@@ -60,6 +60,7 @@ struct reconnect {
     int backoff;
     long long int last_received;
     long long int last_connected;
+    long long int last_disconnected;
     unsigned int max_tries;
 
     /* These values are simply for statistics reporting, not otherwise used
@@ -106,6 +107,7 @@ reconnect_create(long long int now)
     fsm->backoff = 0;
     fsm->last_received = now;
     fsm->last_connected = now;
+    fsm->last_disconnected = now;
     fsm->max_tries = UINT_MAX;
     fsm->creation_time = now;
 
@@ -353,6 +355,9 @@ reconnect_disconnected(struct reconnect *fsm, long long int now, int error)
             }
         }
 
+        if (fsm->state & (S_ACTIVE | S_IDLE)) {
+            fsm->last_disconnected = now;
+        }
         /* Back off. */
         if (fsm->state & (S_ACTIVE | S_IDLE)
              && (fsm->last_received - fsm->last_connected >= fsm->backoff
@@ -646,6 +651,16 @@ reconnect_get_connection_duration(const struct reconnect *fsm,
     return reconnect_is_connected(fsm) ? now - fsm->last_connected : 0;
 }
 
+/* Returns the number of milliseconds for which 'fsm' has been continuously
+ * disconnected from its peer.  (If 'fsm' is not currently connected,
+ * this is 0.) */
+unsigned int
+reconnect_get_disconnect_duration(const struct reconnect *fsm,
+                                  long long int now)
+{
+    return reconnect_is_connected(fsm) ? 0 : now - fsm->last_disconnected;
+}
+
 /* Copies various statistics for 'fsm' into '*stats'. */
 void
 reconnect_get_stats(const struct reconnect *fsm, long long int now,
@@ -654,11 +669,14 @@ reconnect_get_stats(const struct reconnect *fsm, long long int now,
     stats->creation_time = fsm->creation_time;
     stats->last_received = fsm->last_received;
     stats->last_connected = fsm->last_connected;
+    stats->last_disconnected = fsm->last_disconnected;
     stats->backoff = fsm->backoff;
     stats->seqno = fsm->seqno;
     stats->is_connected = reconnect_is_connected(fsm);
     stats->current_connection_duration
         = reconnect_get_connection_duration(fsm, now);
+    stats->current_disconnect_duration
+        = reconnect_get_disconnect_duration(fsm, now);
     stats->total_connected_duration = (stats->current_connection_duration
                                        + fsm->total_connected_duration);
     stats->n_attempted_connections = fsm->n_attempted_connections;
index d316448f701fa8e64c7d77f15eddf8b558960cda..52f1001f18961a0f9fd9c603cac6b0154d4c84d7 100644 (file)
@@ -69,6 +69,8 @@ void reconnect_force_reconnect(struct reconnect *, long long int now);
 bool reconnect_is_connected(const struct reconnect *);
 unsigned int reconnect_get_connection_duration(const struct reconnect *,
                                                long long int now);
+unsigned int reconnect_get_disconnect_duration(const struct reconnect *,
+                                               long long int now);
 
 void reconnect_disconnected(struct reconnect *, long long int now, int error);
 void reconnect_connecting(struct reconnect *, long long int now);
@@ -93,12 +95,14 @@ struct reconnect_stats {
     long long int creation_time;  /* Time reconnect_create() called. */
     long long int last_received; /* Last call to reconnect_received(). */
     long long int last_connected; /* Last call to reconnect_connected(). */
+    long long int last_disconnected; /* Last call to reconnect_disconnected(). */
     int backoff;                  /* Current backoff duration.  */
 
     unsigned int seqno;         /* # of connections + # of disconnections. */
 
     bool is_connected;          /* Currently connected? */
     unsigned int current_connection_duration; /* Time of current connection. */
+    unsigned int current_disconnect_duration; /* Time disconnected (if disconnected). */
     unsigned int total_connected_duration;    /* Sum of all connections. */
     unsigned int n_attempted_connections;
     unsigned int n_successful_connections;
index 90485799b2b3ad165777ecc27fbce08e844f600b..3a7118859c80d2de325b88d46886234991776a28 100644 (file)
@@ -146,6 +146,7 @@ class Reconnect(object):
         self.backoff = 0
         self.last_received = now
         self.last_connected = now
+        self.last_disconnected = now
         self.max_tries = None
 
         self.creation_time = now
@@ -341,6 +342,9 @@ class Reconnect(object):
                     self.info_level("%s: %s attempt timed out"
                                     % (self.name, type))
 
+            if (self.state in (Reconnect.Active, Reconnect.Idle)):
+                self.last_disconnected = now
+
             # Back off
             if (self.state in (Reconnect.Active, Reconnect.Idle) and
                 (self.last_received - self.last_connected >= self.backoff or
@@ -534,17 +538,28 @@ class Reconnect(object):
         else:
             return 0
 
+    def get_disconnect_duration(self, now):
+        """Returns the number of milliseconds for which this FSM has been
+        continuously disconnected from its peer.  (If this FSM is not currently
+        connected, this is 0.)"""
+        if not self.is_connected():
+            return now - self.last_disconnected
+        else:
+            return 0
+
     def get_stats(self, now):
         class Stats(object):
             pass
         stats = Stats()
         stats.creation_time = self.creation_time
         stats.last_connected = self.last_connected
+        stats.last_disconnected = self.last_disconnected
         stats.last_received = self.last_received
         stats.backoff = self.backoff
         stats.seqno = self.seqno
         stats.is_connected = self.is_connected()
         stats.current_connection_duration = self.get_connection_duration(now)
+        stats.current_disconnect_duration = self.get_disconnect_duration(now)
         stats.total_connected_duration = (stats.current_connection_duration +
                                           self.total_connected_duration)
         stats.n_attempted_connections = self.n_attempted_connections
index 559836420a92ce51cb7f97ba353dd4ab23e55587..171c35c47af7061f2fc92c681b027c629fb58c29 100644 (file)
@@ -86,6 +86,7 @@ disconnected
   in BACKOFF for 0 ms (1000 ms backoff)
   1 successful connections out of 1 attempts, seqno 2
   not connected (0 ms), total 10000 ms connected
+  disconnected at 11000 ms (0 ms ago)
 ])
 
 ######################################################################
@@ -125,12 +126,14 @@ advance 500
 
 ### t=1500 ###
   in CONNECT_IN_PROGRESS for 500 ms (0 ms backoff)
+  disconnected for 500 ms
 run
 connected
   in ACTIVE for 0 ms (0 ms backoff)
   created 1000, last received 1000, last connected 1500
   1 successful connections out of 1 attempts, seqno 1
   connected (0 ms), total 0 ms connected
+  disconnected for 0 ms
 
 # Send inactivity probe.
 timeout
@@ -156,6 +159,7 @@ disconnected
   in BACKOFF for 0 ms (1000 ms backoff)
   1 successful connections out of 1 attempts, seqno 2
   not connected (0 ms), total 10000 ms connected
+  disconnected at 11500 ms (0 ms ago)
 ])
 
 ######################################################################
@@ -235,6 +239,7 @@ timeout
 
 ### t=2000 ###
   in CONNECT_IN_PROGRESS for 1000 ms (0 ms backoff)
+  disconnected for 1000 ms
 run
   should disconnect
 connect-failed
@@ -247,6 +252,7 @@ timeout
 
 ### t=3000 ###
   in BACKOFF for 1000 ms (1000 ms backoff)
+  disconnected for 2000 ms
 run
   should connect
 
@@ -258,6 +264,7 @@ timeout
 
 ### t=4000 ###
   in CONNECT_IN_PROGRESS for 1000 ms (1000 ms backoff)
+  disconnected for 3000 ms
 run
   should disconnect
 connect-failed
@@ -270,6 +277,7 @@ timeout
 
 ### t=6000 ###
   in BACKOFF for 2000 ms (2000 ms backoff)
+  disconnected for 5000 ms
 run
   should connect
 
@@ -281,6 +289,7 @@ timeout
 
 ### t=8000 ###
   in CONNECT_IN_PROGRESS for 2000 ms (2000 ms backoff)
+  disconnected for 7000 ms
 run
   should disconnect
 connect-failed
@@ -293,6 +302,7 @@ timeout
 
 ### t=12000 ###
   in BACKOFF for 4000 ms (4000 ms backoff)
+  disconnected for 11000 ms
 run
   should connect
 
@@ -304,6 +314,7 @@ timeout
 
 ### t=16000 ###
   in CONNECT_IN_PROGRESS for 4000 ms (4000 ms backoff)
+  disconnected for 15000 ms
 run
   should disconnect
 connect-failed
@@ -316,6 +327,7 @@ timeout
 
 ### t=24000 ###
   in BACKOFF for 8000 ms (8000 ms backoff)
+  disconnected for 23000 ms
 run
   should connect
 
@@ -327,6 +339,7 @@ timeout
 
 ### t=32000 ###
   in CONNECT_IN_PROGRESS for 8000 ms (8000 ms backoff)
+  disconnected for 31000 ms
 run
   should disconnect
 connect-failed
@@ -339,6 +352,7 @@ timeout
 
 ### t=40000 ###
   in BACKOFF for 8000 ms (8000 ms backoff)
+  disconnected for 39000 ms
 run
   should connect
 
@@ -350,6 +364,7 @@ timeout
 
 ### t=48000 ###
   in CONNECT_IN_PROGRESS for 8000 ms (8000 ms backoff)
+  disconnected for 47000 ms
 run
   should disconnect
 connect-failed
@@ -430,6 +445,7 @@ disconnected
   in BACKOFF for 0 ms (1000 ms backoff)
   1 successful connections out of 1 attempts, seqno 2
   not connected (0 ms), total 10000 ms connected
+  disconnected at 11000 ms (0 ms ago)
 
 # Back off for 1000 ms.
 timeout
@@ -437,6 +453,7 @@ timeout
 
 ### t=12000 ###
   in BACKOFF for 1000 ms (1000 ms backoff)
+  disconnected for 1000 ms
 run
   should connect
 
@@ -448,6 +465,7 @@ connected
   created 1000, last received 1000, last connected 12000
   2 successful connections out of 2 attempts, seqno 3
   connected (0 ms), total 10000 ms connected
+  disconnected for 0 ms
 timeout
   advance 5000 ms
 
@@ -469,6 +487,7 @@ disconnected
   in BACKOFF for 0 ms (2000 ms backoff)
   2 successful connections out of 2 attempts, seqno 4
   not connected (0 ms), total 20000 ms connected
+  disconnected at 22000 ms (0 ms ago)
 
 # Back off for 2000 ms.
 timeout
@@ -476,6 +495,7 @@ timeout
 
 ### t=24000 ###
   in BACKOFF for 2000 ms (2000 ms backoff)
+  disconnected for 2000 ms
 run
   should connect
 
@@ -487,6 +507,7 @@ connected
   created 1000, last received 1000, last connected 24000
   3 successful connections out of 3 attempts, seqno 5
   connected (0 ms), total 20000 ms connected
+  disconnected for 0 ms
 timeout
   advance 5000 ms
 
@@ -508,6 +529,7 @@ disconnected
   in BACKOFF for 0 ms (4000 ms backoff)
   3 successful connections out of 3 attempts, seqno 6
   not connected (0 ms), total 30000 ms connected
+  disconnected at 34000 ms (0 ms ago)
 
 # Back off for 4000 ms.
 timeout
@@ -515,6 +537,7 @@ timeout
 
 ### t=38000 ###
   in BACKOFF for 4000 ms (4000 ms backoff)
+  disconnected for 4000 ms
 ])
 
 ######################################################################
@@ -572,6 +595,7 @@ timeout
 
 ### t=2000 ###
   in CONNECT_IN_PROGRESS for 1000 ms (0 ms backoff)
+  disconnected for 1000 ms
 run
   should disconnect
 connect-failed
@@ -584,6 +608,7 @@ timeout
 
 ### t=3000 ###
   in BACKOFF for 1000 ms (1000 ms backoff)
+  disconnected for 2000 ms
 run
   should connect
 
@@ -595,6 +620,7 @@ timeout
 
 ### t=4000 ###
   in CONNECT_IN_PROGRESS for 1000 ms (1000 ms backoff)
+  disconnected for 3000 ms
 run
   should disconnect
 connect-failed
@@ -607,6 +633,7 @@ timeout
 
 ### t=6000 ###
   in BACKOFF for 2000 ms (2000 ms backoff)
+  disconnected for 5000 ms
 run
   should connect
 
@@ -617,12 +644,14 @@ advance 500
 
 ### t=6500 ###
   in CONNECT_IN_PROGRESS for 500 ms (2000 ms backoff)
+  disconnected for 5500 ms
 run
 connected
   in ACTIVE for 0 ms (2000 ms backoff)
   created 1000, last received 1000, last connected 6500
   1 successful connections out of 3 attempts, seqno 1
   connected (0 ms), total 0 ms connected
+  disconnected for 0 ms
 
 # Connection drops after another 250 ms.
 advance 250
@@ -634,6 +663,7 @@ disconnected
   in BACKOFF for 0 ms (4000 ms backoff)
   1 successful connections out of 3 attempts, seqno 2
   not connected (0 ms), total 250 ms connected
+  disconnected at 6750 ms (0 ms ago)
 run
 
 # Back off for 4000 ms.
@@ -642,6 +672,7 @@ timeout
 
 ### t=10750 ###
   in BACKOFF for 4000 ms (4000 ms backoff)
+  disconnected for 4000 ms
 run
   should connect
 ])
@@ -712,6 +743,7 @@ timeout
 
 ### t=2000 ###
   in CONNECT_IN_PROGRESS for 1000 ms (0 ms backoff)
+  disconnected for 1000 ms
 run
   should disconnect
 connect-failed
@@ -724,6 +756,7 @@ timeout
 
 ### t=3000 ###
   in BACKOFF for 1000 ms (1000 ms backoff)
+  disconnected for 2000 ms
 run
   should connect
 
@@ -735,6 +768,7 @@ timeout
 
 ### t=4000 ###
   in CONNECT_IN_PROGRESS for 1000 ms (1000 ms backoff)
+  disconnected for 3000 ms
 run
   should disconnect
 connect-failed
@@ -747,6 +781,7 @@ timeout
 
 ### t=6000 ###
   in BACKOFF for 2000 ms (2000 ms backoff)
+  disconnected for 5000 ms
 run
   should connect
 
@@ -757,12 +792,14 @@ advance 500
 
 ### t=6500 ###
   in CONNECT_IN_PROGRESS for 500 ms (2000 ms backoff)
+  disconnected for 5500 ms
 run
 connected
   in ACTIVE for 0 ms (2000 ms backoff)
   created 1000, last received 1000, last connected 6500
   1 successful connections out of 3 attempts, seqno 1
   connected (0 ms), total 0 ms connected
+  disconnected for 0 ms
 
 # Connection receives 3 chunks of data spaced 250 ms apart.
 advance 250
@@ -795,6 +832,7 @@ disconnected
   in BACKOFF for 0 ms (4000 ms backoff)
   1 successful connections out of 3 attempts, seqno 2
   not connected (0 ms), total 750 ms connected
+  disconnected at 7250 ms (0 ms ago)
 run
 
 # Back off for 4000 ms.
@@ -803,6 +841,7 @@ timeout
 
 ### t=11250 ###
   in BACKOFF for 4000 ms (4000 ms backoff)
+  disconnected for 4000 ms
 run
   should connect
 ])
@@ -873,6 +912,7 @@ timeout
 
 ### t=2000 ###
   in CONNECT_IN_PROGRESS for 1000 ms (0 ms backoff)
+  disconnected for 1000 ms
 run
   should disconnect
 connect-failed
@@ -885,6 +925,7 @@ timeout
 
 ### t=3000 ###
   in BACKOFF for 1000 ms (1000 ms backoff)
+  disconnected for 2000 ms
 run
   should connect
 
@@ -896,6 +937,7 @@ timeout
 
 ### t=4000 ###
   in CONNECT_IN_PROGRESS for 1000 ms (1000 ms backoff)
+  disconnected for 3000 ms
 run
   should disconnect
 connect-failed
@@ -908,6 +950,7 @@ timeout
 
 ### t=6000 ###
   in BACKOFF for 2000 ms (2000 ms backoff)
+  disconnected for 5000 ms
 run
   should connect
 
@@ -918,12 +961,14 @@ advance 500
 
 ### t=6500 ###
   in CONNECT_IN_PROGRESS for 500 ms (2000 ms backoff)
+  disconnected for 5500 ms
 run
 connected
   in ACTIVE for 0 ms (2000 ms backoff)
   created 1000, last received 1000, last connected 6500
   1 successful connections out of 3 attempts, seqno 1
   connected (0 ms), total 0 ms connected
+  disconnected for 0 ms
 
 # Connection receives 3 chunks of data spaced 2000 ms apart.
 advance 2000
@@ -956,6 +1001,7 @@ disconnected
   in BACKOFF for 0 ms (1000 ms backoff)
   1 successful connections out of 3 attempts, seqno 2
   not connected (0 ms), total 6000 ms connected
+  disconnected at 12500 ms (0 ms ago)
 run
 
 # Back off for 1000 ms.
@@ -964,6 +1010,7 @@ timeout
 
 ### t=13500 ###
   in BACKOFF for 1000 ms (1000 ms backoff)
+  disconnected for 1000 ms
 run
   should connect
 ])
@@ -1006,6 +1053,7 @@ timeout
 
 ### t=2000 ###
   in BACKOFF for 1000 ms (1000 ms backoff)
+  disconnected for 1000 ms
 
 # Connection fails quickly again.
 run
@@ -1021,6 +1069,7 @@ timeout
 
 ### t=4000 ###
   in BACKOFF for 2000 ms (2000 ms backoff)
+  disconnected for 3000 ms
 ])
 
 ######################################################################
@@ -1080,6 +1129,7 @@ disconnected
   in VOID for 0 ms (1000 ms backoff)
   1 successful connections out of 1 attempts, seqno 2
   not connected (0 ms), total 10000 ms connected
+  disconnected at 11000 ms (0 ms ago)
 ])
 
 ######################################################################
@@ -1162,6 +1212,7 @@ timeout
 
 ### t=2000 ###
   in BACKOFF for 1000 ms (1000 ms backoff)
+  disconnected for 1000 ms
 run
   should connect
 listening
@@ -1173,6 +1224,7 @@ connected
   created 1000, last received 1000, last connected 2000
   1 successful connections out of 1 attempts, seqno 1
   connected (0 ms), total 0 ms connected
+  disconnected for 0 ms
 received
   created 1000, last received 2000, last connected 2000
 advance 1000
@@ -1205,6 +1257,7 @@ disconnected
   in BACKOFF for 0 ms (0 ms backoff)
   1 successful connections out of 1 attempts, seqno 2
   not connected (0 ms), total 11000 ms connected
+  disconnected at 13000 ms (0 ms ago)
 
 # Start listening again.
 timeout
index 0f49d7f5847c0bc590a7ca279b35b17d24e76b67..2d654ff8a72499214e26e2aae16cd02b612cf8ce 100644 (file)
@@ -237,6 +237,13 @@ diff_stats(const struct reconnect_stats *old,
                new->current_connection_duration,
                new->total_connected_duration);
     }
+    if (old->last_disconnected != new->last_disconnected) {
+        printf("  disconnected at %llu ms (%u ms ago)\n",
+               new->last_disconnected, new->current_disconnect_duration);
+    }
+    if (old->current_disconnect_duration != new->current_disconnect_duration) {
+        printf("  disconnected for %llu ms\n", new->current_disconnect_duration);
+    }
 }
 
 static void
index 4b483db095db77acddb283e2212662d885363be9..0c467564c1b6b0e8c7932d3bad009876f70091b0 100644 (file)
@@ -117,6 +117,13 @@ def diff_stats(old, new):
               % (negate, new.current_connection_duration,
                  new.total_connected_duration))
 
+    if (old.last_disconnected != new.last_disconnected):
+        print("  disconnected at %d ms (%d ms ago)"
+              % (new.last_disconnected, new.current_disconnect_duration))
+
+    if (old.current_disconnect_duration != new.current_disconnect_duration):
+        print("  disconnected for %d ms" % (new.current_disconnect_duration))
+
 def do_set_passive(arg):
     r.set_passive(True, now)