logger.c: Retry file lock also after ENOLCK

This means "No locks available".  We now handle it just like EAGAIN,
retrying and hoping for recover.

Also adds diagnostic output of the lock delay when this happens.

src/logger.c

@@ -58,6 +58,7 @@
 #include "cracker.h"
 #include "signals.h"
 #include "logger.h"
+#include "timer.h"
 
 static int cfg_beep;
 static int cfg_log_passwords;
@@ -136,24 +137,39 @@ int log_lock(int fd, int cmd, int type, const char *name,
 	        : cmd == F_UNLCK ? "F_UNLCK" : "");
 #endif
 
+	uint64_t lock_start = 0;
+	int warned = 0;
+	int retry = 0;
+
 	lock.l_type = type;
 	while (fcntl(fd, cmd, &lock)) {
-		if (errno == EAGAIN) {
-			static int warned;
+		if (errno == EAGAIN || errno == ENOLCK) {
 			struct timeval t;
+			unsigned int warn_bit = (errno == EAGAIN ? 1 : 2);
 
 			if (cmd == F_SETLK)
 				return -1;
 
-			if (!warned++) {
-				log_event("Got EAGAIN despite F_SETLKW (only logged once per node) %s:%d %s", source_file, line, function);
-				fprintf(stderr, "Node %d: File locking apparently exhausted, check ulimits and any NFS server limits. This is recoverable but will harm performance (muting further of these messages from same node)\n", NODE);
+			if (!(warned & warn_bit)) {
+				char *err_str = (errno == EAGAIN ? "EAGAIN" : "ENOLCK");
+
+				if (!lock_start)
+					lock_start = john_get_nano();
+
+				log_event("- Got %s despite F_SETLKW on %s, %s() %s:%d", err_str, name, function, source_file, line);
+				if (options.node_count)
+					fprintf(stderr, "%u: ", NODE);
+				fprintf(stderr, "File locking apparently exhausted (%s), retrying. Check ulimits and any NFS server limits\n", err_str);
 				srand(NODE);
+
+				warned |= warn_bit;
 			}
 
 			/* Sleep for a random time of max. ~260 ms */
 			t.tv_sec = 0; t.tv_usec = (rand() & 1023) << 8;
 			select(0, NULL, NULL, NULL, &t);
+
+			retry++;
 			continue;
 		} else if (errno != EINTR)
 			pexit("%s:%d %s() fcntl(%s, %s, %s)",
@@ -164,6 +180,15 @@ int log_lock(int fd, int cmd, int type, const char *name,
 			      : cmd == F_UNLCK ? "F_UNLCK" : "");
 	}
 
+	if (lock_start) {
+		char *delay_str = human_prefix_small((john_get_nano() - lock_start) / 1E9);
+
+		log_event("+ Got a lock after %ss", delay_str);
+		if (options.node_count)
+			fprintf(stderr, "%u: ", NODE);
+		fprintf(stderr, "Got a lock on %s after %d retr%s, %ss\n", name, retry, retry > 1 ? "ies" : "y", delay_str);
+	}
+
 #ifdef LOCK_DEBUG
 	fprintf(stderr, "%u: %s(): Locked %s\n", NODE, function, name);
 #endif