Merge pull request #600 from pre-commit/print_locking_less

Only print that the lock is being acquired when waiting

pre_commit/file_lock.py

@@ -12,18 +12,22 @@ try:  # pragma: no cover (windows)
     _region = 0xffff
 
     @contextlib.contextmanager
-    def _locked(fileno):
+    def _locked(fileno, blocked_cb):
-        while True:
+        try:
-            try:
+            msvcrt.locking(fileno, msvcrt.LK_NBLCK, _region)
-                msvcrt.locking(fileno, msvcrt.LK_LOCK, _region)
+        except IOError:
-            except OSError as e:
+            blocked_cb()
-                # Locking violation. Returned when the _LK_LOCK or _LK_RLCK
+            while True:
-                # flag is specified and the file cannot be locked after 10
+                try:
-                # attempts.
+                    msvcrt.locking(fileno, msvcrt.LK_LOCK, _region)
-                if e.errno != errno.EDEADLOCK:
+                except IOError as e:
-                    raise
+                    # Locking violation. Returned when the _LK_LOCK or _LK_RLCK
-            else:
+                    # flag is specified and the file cannot be locked after 10
-                break
+                    # attempts.
+                    if e.errno != errno.EDEADLOCK:
+                        raise
+                else:
+                    break
 
         try:
             yield
@@ -38,8 +42,12 @@ except ImportError:  # pragma: no cover (posix)
     import fcntl
 
     @contextlib.contextmanager
-    def _locked(fileno):
+    def _locked(fileno, blocked_cb):
-        fcntl.flock(fileno, fcntl.LOCK_EX)
+        try:
+            fcntl.flock(fileno, fcntl.LOCK_EX | fcntl.LOCK_NB)
+        except IOError:
+            blocked_cb()
+            fcntl.flock(fileno, fcntl.LOCK_EX)
         try:
             yield
         finally:
@@ -47,7 +55,7 @@ except ImportError:  # pragma: no cover (posix)
 
 
 @contextlib.contextmanager
-def lock(path):
+def lock(path, blocked_cb):
     with open(path, 'a+') as f:
-        with _locked(f.fileno()):
+        with _locked(f.fileno(), blocked_cb):
             yield

pre_commit/store.py

@@ -47,10 +47,11 @@ class Store(object):
         self.directory = directory
 
     @contextlib.contextmanager
-    def exclusive_lock(self, quiet=False):
+    def exclusive_lock(self):
-        if not quiet:
+        def blocked_cb():  # pragma: no cover (tests are single-process)
             logger.info('Locking pre-commit directory')
-        with file_lock.lock(os.path.join(self.directory, '.lock')):
+
+        with file_lock.lock(os.path.join(self.directory, '.lock'), blocked_cb):
             yield
 
     def _write_readme(self):
@@ -89,7 +90,7 @@ class Store(object):
 
         if os.path.exists(self.db_path):
             return
-        with self.exclusive_lock(quiet=True):
+        with self.exclusive_lock():
             # Another process may have already completed this work
             if os.path.exists(self.db_path):  # pragma: no cover (race)
                 return

tests/commands/install_uninstall_test.py

@@ -142,8 +142,7 @@ FILES_CHANGED = (
 
 
 NORMAL_PRE_COMMIT_RUN = re.compile(
-    r'^\[INFO\] Locking pre-commit directory\r?\n'
+    r'^\[INFO\] Initializing environment for .+\.\r?\n'
-    r'\[INFO\] Initializing environment for .+\.\r?\n'
     r'Bash hook\.+Passed\r?\n'
     r'\[master [a-f0-9]{7}\] Commit!\r?\n' +
     FILES_CHANGED +
@@ -255,8 +254,7 @@ def test_environment_not_sourced(tempdir_factory):
 
 
 FAILING_PRE_COMMIT_RUN = re.compile(
-    r'^\[INFO\] Locking pre-commit directory\r?\n'
+    r'^\[INFO\] Initializing environment for .+\.\r?\n'
-    r'\[INFO\] Initializing environment for .+\.\r?\n'
     r'Failing hook\.+Failed\r?\n'
     r'hookid: failing_hook\r?\n'
     r'\r?\n'
@@ -334,7 +332,6 @@ def test_install_existing_hook_no_overwrite_idempotent(tempdir_factory):
 
 FAIL_OLD_HOOK = re.compile(
     r'fail!\r?\n'
-    r'\[INFO\] Locking pre-commit directory\r?\n'
     r'\[INFO\] Initializing environment for .+\.\r?\n'
     r'Bash hook\.+Passed\r?\n',
 )

tests/repository_test.py

@@ -559,8 +559,8 @@ def test_reinstall(tempdir_factory, store, log_info_mock):
     config = make_config_from_repo(path)
     repo = Repository.create(config, store)
     repo.require_installed()
-    # We print some logging during clone (2) + install (4)
+    # We print some logging during clone (1) + install (3)
-    assert log_info_mock.call_count == 6
+    assert log_info_mock.call_count == 4
     log_info_mock.reset_mock()
     # Reinstall with same repo should not trigger another install
     repo.require_installed()

tests/store_test.py

@@ -88,7 +88,7 @@ def test_clone(store, tempdir_factory, log_info_mock):
 
     ret = store.clone(path, sha)
     # Should have printed some stuff
-    assert log_info_mock.call_args_list[1][0][0].startswith(
+    assert log_info_mock.call_args_list[0][0][0].startswith(
         'Initializing environment for ',
     )