Add locking for all access to sessions/* and logs/*.

This should solve race conditions between cron and the web server when they
try to access the same log file.

votrfront/cron.py

@@ -9,6 +9,7 @@
 import tarfile
 import time
 from . import logutil
+from . import sessions
 
 
 def create_archive(app, prefix):
@@ -61,25 +62,28 @@ def cron(app):
     now = time.time()
 
     for sessid in os.listdir(app.var_path('sessions')):
-        path = app.var_path('sessions', sessid)
-        mtime = os.path.getmtime(path)
-        if now - mtime > app.settings.session_max_age:
-            os.unlink(path)
+        with sessions.lock(app, sessid):
+            path = app.var_path('sessions', sessid)
+            if not os.path.exists(path): continue  # Logged out just now?
+            mtime = os.path.getmtime(path)
+            if now - mtime > app.settings.session_max_age:
+                os.unlink(path)
 
     for filename in os.listdir(app.var_path('logs')):
         if not filename.endswith('.gz'): continue
         path = app.var_path('logs', filename)
         sessid = filename.partition('.')[0]
-        mtime = os.path.getmtime(path)
-        if not (now - mtime > app.settings.session_max_age): continue
-        if os.path.exists(app.var_path('sessions', sessid)): continue
+        with sessions.lock(app, sessid):
+            mtime = os.path.getmtime(path)
+            if not (now - mtime > app.settings.session_max_age): continue
+            if os.path.exists(app.var_path('sessions', sessid)): continue
 
-        newpath = app.var_path('oldlogs', sessid + '.xz')
+            newpath = app.var_path('oldlogs', sessid + '.xz')
 
-        with gzip.open(path) as src:
-            with lzma.open(newpath, 'w', preset=9) as dest:
-                shutil.copyfileobj(src, dest)
-        os.unlink(path)
+            with gzip.open(path) as src:
+                with lzma.open(newpath, 'w', preset=9) as dest:
+                    shutil.copyfileobj(src, dest)
+            os.unlink(path)
 
     this_month = datetime.datetime.utcfromtimestamp(now).strftime('%Y%m')
     prefixes = set(

votrfront/default_settings.py

@@ -3,6 +3,8 @@
 
 var_path = '.'
 
+lock_path = '/run/lock'
+
 session_max_age = 60 * 60 * 24
 
 log_max_age = 60 * 60 * 25

votrfront/login.py

@@ -36,15 +36,15 @@ def do_logout(request):
                 log('logout',
                     'Logout failed with {}'.format(type(e).__name__),
                     traceback.format_exc())
-                # But clear the session and save it anyway.
+                # But delete the session anyway.
             else:
                 log('logout', 'Logout finished')
-            session.clear()
+            sessions.delete(request)
+            # When the with statement ends, the session dict is still written
+            # to the open session fd, but the file was already deleted.
     except Exception:
         pass
 
-    sessions.delete(request)
-
     return credentials
 
 
@@ -62,7 +62,8 @@ def finish_login(request, destination, params):
         fladgejt_params = params
 
     sessid = datetime.utcnow().strftime('%Y%m%d_') + generate_key()
-    with sessions.open_log_file(request, sessid) as log_file:
+    with sessions.lock(request.app, sessid), \
+            sessions.open_log_file(request, sessid) as log_file:
         logger = Logger()
         logger.log_file = log_file
 

votrfront/logutil.py

@@ -10,6 +10,7 @@
 import subprocess
 import sys
 import time
+from . import sessions
 
 
 TAG_PREFIX = '%'
@@ -124,7 +125,7 @@ def process_logfiles(app, files):
 
     for filename in files:
         sessid = os.path.basename(filename).partition('.')[0]
-        with open_log(filename) as f:
+        with sessions.lock(app, sessid), open_log(filename) as f:
             lineno = 0
             for line in f:
                 lineno += 1

votrfront/sessions.py

@@ -19,11 +19,14 @@ def set_session_cookie(request, response, sessid):
     return response
 
 
-def get_filename(request, sessid, *, logs=False):
+def check_sessid(sessid):
     for ch in sessid:
         if ch not in '0123456789abcdef_':
             raise ValueError('Invalid sessid')
 
+
+def get_filename(request, sessid, *, logs=False):
+    check_sessid(sessid)
     return request.app.var_path('logs' if logs else 'sessions', sessid)
 
 
@@ -49,40 +52,76 @@ def delete(request, sessid=None):
         return False
 
 
+@contextlib.contextmanager
+def lock(app, sessid):
+    """Acquires a named mutex identified by ``sessid``, waiting if another
+    process/thread is already holding it. If a process dies, its held locks are
+    automatically released. Locks are per user."""
+    # This is implemented with file locks, specifically BSD locks (flock). See
+    # https://gavv.github.io/articles/file-locks/ for a comparison. lockf and
+    # POSIX locks (fcntl) behave badly on close (threads can unlock each other).
+    #
+    # Instead of locking the session file or the log file, we use dedicated
+    # lock files, because it can be significant to delete the session or log
+    # file while the sessid is still locked.
+    #
+    # The lock file is deleted when we're done (to clean up after ourselves). We
+    # use the algorithm from https://stackoverflow.com/q/17708885 to avoid race
+    # conditions when one thread deletes the file but another thread already has
+    # it open and is trying to lock it.
+    check_sessid(sessid)
+    lock_path = os.path.join(
+        app.settings.lock_path,
+        '{}.{}.{}'.format(app.settings.instance_name, os.getuid(), sessid))
+    while True:
+        f = open(lock_path, 'ab')
+        try:
+            fcntl.flock(f.fileno(), fcntl.LOCK_EX)
+
+            # Lock acquired, but is it still the same file? Compare inodes.
+            my_inode = os.fstat(f.fileno()).st_ino
+            try:
+                inode_on_disk = os.stat(lock_path).st_ino
+            except FileNotFoundError:
+                inode_on_disk = None
+            if my_inode != inode_on_disk:
+                # File was already deleted. Close it and try to open it again.
+                continue
+
+            try:
+                yield
+            finally:
+                # Whether the body succeeded or not, unlink and close the file.
+                os.unlink(lock_path)
+
+            return
+        finally:
+            f.close()
+
+
 @contextlib.contextmanager
 def transaction(request, sessid=None):
     if not sessid: sessid = get_session_cookie(request)
     if not sessid: raise LoggedOutError('Session cookie not found')
 
-    try:
-        f = open(get_filename(request, sessid), 'r+b')
-    except FileNotFoundError as e:
-        raise LoggedOutError('Votr session does not exist') from e
-
-    with f:
-        # Use flock instead of fcntl or lockf. flock has sane semantics on
-        # close(2), and we don't need fcntl's byte range locks.
-        fcntl.flock(f.fileno(), fcntl.LOCK_EX)
-
-        session = pickle.load(f)
-
-        if not session:
-            # If the session is empty, there was probably a race between this
-            # request and a logout. The logout arrived first, emptied the
-            # session, saved it and unlinked the file. But this request already
-            # managed to open the file and was waiting for flock while that was
-            # happening. We can react as if the session file didn't exist.
-            raise LoggedOutError('Votr session is currently logging out')
-
-        yield session
-
-        # Use pickle.dumps instead of pickle.dump, so that if it fails, the
-        # session file is not truncated.
-        new_content = pickle.dumps(session, pickle.HIGHEST_PROTOCOL)
-
-        f.seek(0)
-        f.truncate(0)
-        f.write(new_content)
+    with lock(request.app, sessid):
+        try:
+            f = open(get_filename(request, sessid), 'r+b')
+        except FileNotFoundError as e:
+            raise LoggedOutError('Votr session does not exist') from e
+
+        with f:
+            session = pickle.load(f)
+
+            yield session
+
+            # Use pickle.dumps instead of pickle.dump, so that if it fails, the
+            # session file is not truncated.
+            new_content = pickle.dumps(session, pickle.HIGHEST_PROTOCOL)
+
+            f.seek(0)
+            f.truncate(0)
+            f.write(new_content)
 
 
 @contextlib.contextmanager