lockfile: Don't warn if successful lock takes a little time.

This code issues a warning if obtaining a lock takes even 1 millisecond.
That's far too aggressive.  There's no need to warn if we have to wait
a few milliseconds.  This function already warns elsewhere if locking takes
more than 1 second, which is much more reasonable.

This change allows us to test ovsdb-server stderr output more carefully.
Before now, the tests had to ignore what ovsdb-server writes to stderr
because sometimes it would log a warning that locking took 1 ms (or so).

Reviewed-by: Simon Horman <horms@verge.net.au>

4 files changed, 15 insertions, 20 deletions

diff --git a/lib/lockfile.c b/lib/lockfile.c
index 771ad70c..43ccaf98 100644
--- a/lib/lockfile.c
+++ b/lib/lockfile.c
@@ -1,4 +1,4 @@
- /* Copyright (c) 2008, 2009, 2010 Nicira Networks
+ /* Copyright (c) 2008, 2009, 2010, 2011 Nicira Networks
  *
  * Licensed under the Apache License, Version 2.0 (the "License");
  * you may not use this file except in compliance with the License.
@@ -111,17 +111,12 @@ lockfile_lock(const char *file, int timeout, struct lockfile **lockfilep)
         }
     } while (error == EINTR && (timeout == INT_MAX || elapsed < timeout));
 
-    if (!error) {
-        if (elapsed) {
-            VLOG_WARN("%s: waited %lld ms for lock file",
-                      lock_name, elapsed);
-        }
-    } else if (error == EINTR) {
+    if (error == EINTR) {
         COVERAGE_INC(lockfile_timeout);
         VLOG_WARN("%s: giving up on lock file after %lld ms",
                   lock_name, elapsed);
         error = ETIMEDOUT;
-    } else {
+    } else if (error) {
         COVERAGE_INC(lockfile_error);
         if (error == EACCES) {
             error = EAGAIN;
diff --git a/tests/daemon.at b/tests/daemon.at
index a97b05c5..f7154e8a 100644
--- a/tests/daemon.at
+++ b/tests/daemon.at
@@ -7,7 +7,7 @@ AT_CAPTURE_FILE([pid])
 AT_CAPTURE_FILE([expected])
 # Start the daemon and wait for the pidfile to get created
 # and that its contents are the correct pid.
-AT_CHECK([ovsdb-server --pidfile=$PWD/pid --remote=punix:socket --unixctl=$PWD/unixctl db& echo $! > expected], [0], [ignore], [ignore])
+AT_CHECK([ovsdb-server --pidfile=$PWD/pid --remote=punix:socket --unixctl=$PWD/unixctl db& echo $! > expected], [0])
 OVS_WAIT_UNTIL([test -s pid], [kill `cat expected`])
 AT_CHECK(
   [pid=`cat pid` && expected=`cat expected` && test "$pid" = "$expected"],
@@ -27,7 +27,7 @@ AT_CAPTURE_FILE([parent])
 AT_CAPTURE_FILE([parentpid])
 AT_CAPTURE_FILE([newpid])
 # Start the daemon and wait for the pidfile to get created.
-AT_CHECK([ovsdb-server --monitor --pidfile=$PWD/pid --remote=punix:socket --unixctl=$PWD/unixctl db& echo $! > parent], [0], [ignore], [ignore])
+AT_CHECK([ovsdb-server --monitor --pidfile=$PWD/pid --remote=punix:socket --unixctl=$PWD/unixctl db& echo $! > parent], [0])
 OVS_WAIT_UNTIL([test -s pid], [kill `cat parent`])
 # Check that the pidfile names a running process,
 # and that the parent process of that process is our child process.
@@ -70,7 +70,7 @@ OVSDB_INIT([db])
 # Start the daemon and make sure that the pidfile exists immediately.
 # We don't wait for the pidfile to get created because the daemon is
 # supposed to do so before the parent exits.
-AT_CHECK([ovsdb-server --detach --pidfile=$PWD/pid --remote=punix:socket --unixctl=$PWD/unixctl db], [0], [ignore], [ignore])
+AT_CHECK([ovsdb-server --detach --pidfile=$PWD/pid --remote=punix:socket --unixctl=$PWD/unixctl db], [0])
 AT_CHECK([test -s pid])
 AT_CHECK([kill -0 `cat pid`])
 # Kill the daemon and make sure that the pidfile gets deleted.
@@ -94,7 +94,7 @@ AT_CAPTURE_FILE([init])
 # Start the daemon and make sure that the pidfile exists immediately.
 # We don't wait for the pidfile to get created because the daemon is
 # supposed to do so before the parent exits.
-AT_CHECK([ovsdb-server --detach --pidfile=$PWD/daemon --monitor --remote=punix:socket --unixctl=$PWD/unixctl db], [0], [ignore], [ignore])
+AT_CHECK([ovsdb-server --detach --pidfile=$PWD/daemon --monitor --remote=punix:socket --unixctl=$PWD/unixctl db], [0])
 AT_CHECK([test -s daemon])
 # Check that the pidfile names a running process,
 # and that the parent process of that process is a running process,
@@ -107,7 +107,7 @@ CHECK([test `cat init` = 1])
 # Kill the daemon process, making it look like a segfault,
 # and wait for a new daemon process to get spawned.
 CHECK([cp daemon olddaemon])
-CHECK([kill -SEGV `cat daemon`], [0], [ignore], [ignore])
+CHECK([kill -SEGV `cat daemon`], [0])
 OVS_WAIT_WHILE([kill -0 `cat olddaemon`], [kill `cat olddaemon daemon`])
 OVS_WAIT_UNTIL([test -s daemon && test `cat daemon` != `cat olddaemon`],
   [kill `cat olddaemon daemon`])
diff --git a/tests/ovsdb-log.at b/tests/ovsdb-log.at
index f7b6432e..bd061105 100644
--- a/tests/ovsdb-log.at
+++ b/tests/ovsdb-log.at
@@ -46,7 +46,7 @@ AT_CHECK(
 file: read: [1]
 ]], [ignore])
 AT_CHECK(
-  [test-ovsdb -vlockfile:console:emer log-io file create read], [1], 
+  [test-ovsdb log-io file create read], [1],
   [], [test-ovsdb: I/O error: create: file failed (File exists)
 ])
 AT_CHECK([test -f .file.~lock~])
diff --git a/tests/ovsdb-server.at b/tests/ovsdb-server.at
index b603cf7d..d7c0335e 100644
--- a/tests/ovsdb-server.at
+++ b/tests/ovsdb-server.at
@@ -50,7 +50,7 @@ AT_DATA([txnfile], [[ovsdb-client transact unix:socket \
    "table": "ordinals",
    "row": {"number": 0, "name": "zero"}}]'
 ]])
-AT_CHECK([ovsdb-server -vlockfile:ANY:EMER --remote=punix:socket --unixctl=$PWD/unixctl db --run="sh txnfile"], [0], [stdout], [])
+AT_CHECK([ovsdb-server --remote=punix:socket --unixctl=$PWD/unixctl db --run="sh txnfile"], [0], [stdout], [])
 cat stdout >> output
 dnl Add some crap to the database log and run another transaction, which should
 dnl ignore the crap and truncate it out of the log.
@@ -61,7 +61,7 @@ AT_DATA([txnfile], [[ovsdb-client transact unix:socket \
    "table": "ordinals",
    "row": {"number": 1, "name": "one"}}]'
 ]])
-AT_CHECK([ovsdb-server -vlockfile:ANY:EMER --remote=punix:socket --unixctl=$PWD/unixctl db --run="sh txnfile"], [0], [stdout], [stderr])
+AT_CHECK([ovsdb-server --remote=punix:socket --unixctl=$PWD/unixctl db --run="sh txnfile"], [0], [stdout], [stderr])
 AT_CHECK([grep 'syntax error: db: parse error.* in header line "xxx"' stderr],
   [0], [ignore])
 cat stdout >> output
@@ -75,7 +75,7 @@ AT_DATA([txnfile], [[ovsdb-client transact unix:socket \
    "where": [],
    "sort": ["number"]}]'
 ]])
-AT_CHECK([ovsdb-server -vlockfile:ANY:EMER --remote=punix:socket --unixctl=$PWD/unixctl db --run="sh txnfile"], [0], [stdout], [])
+AT_CHECK([ovsdb-server --remote=punix:socket --unixctl=$PWD/unixctl db --run="sh txnfile"], [0], [stdout], [])
 cat stdout >> output
 AT_CHECK([perl $srcdir/uuidfilt.pl output], [0],
   [[[{"uuid":["uuid","<0>"]}]
@@ -97,7 +97,7 @@ AT_DATA([txnfile], [[ovsdb-client transact unix:socket \
    "table": "ordinals",
    "row": {"number": 0, "name": "zero"}}]'
 ]])
-AT_CHECK([ovsdb-server -vlockfile:ANY:EMER --remote=punix:socket --unixctl=$PWD/unixctl db --run="sh txnfile"], [0], [stdout], [])
+AT_CHECK([ovsdb-server --remote=punix:socket --unixctl=$PWD/unixctl db --run="sh txnfile"], [0], [stdout], [])
 cat stdout >> output
 dnl Add some crap to the database log and run another transaction, which should
 dnl ignore the crap and truncate it out of the log.
@@ -109,7 +109,7 @@ AT_DATA([txnfile], [[ovsdb-client transact unix:socket \
    "table": "ordinals",
    "row": {"number": 1, "name": "one"}}]'
 ]])
-AT_CHECK([ovsdb-server -vlockfile:ANY:EMER --remote=punix:socket --unixctl=$PWD/unixctl db --run="sh txnfile"], [0], [stdout], [stderr])
+AT_CHECK([ovsdb-server --remote=punix:socket --unixctl=$PWD/unixctl db --run="sh txnfile"], [0], [stdout], [stderr])
 AT_CHECK([grep 'syntax "{"invalid":{}}": unknown table: No table named invalid.' stderr],
   [0], [ignore])
 cat stdout >> output
@@ -123,7 +123,7 @@ AT_DATA([txnfile], [[ovsdb-client transact unix:socket \
    "where": [],
    "sort": ["number"]}]'
 ]])
-AT_CHECK([ovsdb-server -vlockfile:ANY:EMER --remote=punix:socket --unixctl=$PWD/unixctl db --run="sh txnfile"], [0], [stdout], [])
+AT_CHECK([ovsdb-server --remote=punix:socket --unixctl=$PWD/unixctl db --run="sh txnfile"], [0], [stdout], [])
 cat stdout >> output
 AT_CHECK([perl $srcdir/uuidfilt.pl output], [0],
   [[[{"uuid":["uuid","<0>"]}]