cfg: Log accurate waiting times in cfg_lock().

When cfg_lock() has to block for some time to obtain the configuration file
lock, it logs the amount of time that it waited.  However, it did not
refresh the current time before it began waiting, so the time that it
logged could be off by a significant amount, which make interpreting the
log file more challenging than it should have been.

This change should mainly affect log output.  It should have little or no
effect on Open vSwitch operation because the factor by which the timeouts
were off is an order of magnitude smaller than the actual timeouts that we
pass into the function.

This is related to bug #1426, but it is not a fix for this bug, which will
be committed separately.

diff --git a/lib/cfg.c b/lib/cfg.c
index 833e6e5..901315e 100644 (file)
--- a/lib/cfg.c
+++ b/lib/cfg.c
@@ -332,13 +332,16 @@ try_lock(int fd, bool block)
 int
 cfg_lock(uint8_t *cookie, int timeout)
 {
-    long long int start = time_msec();
+    long long int start;
     long long int elapsed = 0;
     int fd;
     uint8_t curr_cookie[CFG_COOKIE_LEN];
 
     assert(lock_fd < 0);
     COVERAGE_INC(cfg_lock);
+
+    time_refresh();
+    start = time_msec();
     for (;;) {
         int error;