8288: Do not call operations.destroy() as a last resort, just abandon the llfuse...
[arvados.git] / services / fuse / arvados_fuse / __init__.py
index eba17b37c35c420bbc476850bc813a72a9c2cc9c..6ac51f43873d94ca853167b8ad4b4fefbe6e4139 100644 (file)
@@ -66,6 +66,7 @@ import itertools
 import ciso8601
 import collections
 import functools
+import arvados.keep
 
 import Queue
 
@@ -75,7 +76,7 @@ import Queue
 
 llfuse.capi._notify_queue = Queue.Queue()
 
-from fusedir import sanitize_filename, Directory, CollectionDirectory, MagicDirectory, TagsDirectory, ProjectDirectory, SharedDirectory, CollectionDirectoryBase
+from fusedir import sanitize_filename, Directory, CollectionDirectory, TmpCollectionDirectory, MagicDirectory, TagsDirectory, ProjectDirectory, SharedDirectory, CollectionDirectoryBase
 from fusefile import StringFile, FuseArvadosFile
 
 _logger = logging.getLogger('arvados.arvados_fuse')
@@ -99,7 +100,8 @@ class Handle(object):
         self.obj.dec_use()
 
     def flush(self):
-        return self.obj.flush()
+        if self.obj.writable():
+            return self.obj.flush()
 
 
 class FileHandle(Handle):
@@ -147,7 +149,9 @@ class InodeCache(object):
         self._total -= obj.cache_size
         del self._entries[obj.cache_priority]
         if obj.cache_uuid:
-            del self._by_uuid[obj.cache_uuid]
+            self._by_uuid[obj.cache_uuid].remove(obj)
+            if not self._by_uuid[obj.cache_uuid]:
+                del self._by_uuid[obj.cache_uuid]
             obj.cache_uuid = None
         if clear:
             _logger.debug("InodeCache cleared %i total now %i", obj.inode, self._total)
@@ -167,9 +171,13 @@ class InodeCache(object):
             self._entries[obj.cache_priority] = obj
             obj.cache_uuid = obj.uuid()
             if obj.cache_uuid:
-                self._by_uuid[obj.cache_uuid] = obj
+                if obj.cache_uuid not in self._by_uuid:
+                    self._by_uuid[obj.cache_uuid] = [obj]
+                else:
+                    if obj not in self._by_uuid[obj.cache_uuid]:
+                        self._by_uuid[obj.cache_uuid].append(obj)
             self._total += obj.objsize()
-            _logger.debug("InodeCache touched %i (size %i) total now %i", obj.inode, obj.objsize(), self._total)
+            _logger.debug("InodeCache touched %i (size %i) (uuid %s) total now %i", obj.inode, obj.objsize(), obj.cache_uuid, self._total)
             self.cap_cache()
         else:
             obj.cache_priority = None
@@ -184,8 +192,13 @@ class InodeCache(object):
         if obj.persisted() and obj.cache_priority in self._entries:
             self._remove(obj, True)
 
-    def find(self, uuid):
-        return self._by_uuid.get(uuid)
+    def find_by_uuid(self, uuid):
+        return self._by_uuid.get(uuid, [])
+
+    def clear(self):
+        self._entries.clear()
+        self._by_uuid.clear()
+        self._total = 0
 
 class Inodes(object):
     """Manage the set of inodes.  This is the mapping from a numeric id
@@ -227,41 +240,33 @@ class Inodes(object):
 
     def del_entry(self, entry):
         if entry.ref_count == 0:
-            _logger.debug("Deleting inode %i", entry.inode)
             self.inode_cache.unmanage(entry)
-            _logger.debug("(1) unmanaged inode %i", entry.inode)
-
             del self._entries[entry.inode]
-            _logger.debug("(2) deleted inode %i", entry.inode)
-
             with llfuse.lock_released:
                 entry.finalize()
-                _logger.debug("(3) finalized inode %i", entry.inode)
-
             self.invalidate_inode(entry.inode)
-            _logger.debug("(4) invalidated inode %i", entry.inode)
-
             entry.inode = None
         else:
             entry.dead = True
             _logger.debug("del_entry on inode %i with refcount %i", entry.inode, entry.ref_count)
 
     def invalidate_inode(self, inode):
-        self.deferred_invalidations.append((inode,))
+        llfuse.invalidate_inode(inode)
 
     def invalidate_entry(self, inode, name):
-        self.deferred_invalidations.append((inode, name))
+        llfuse.invalidate_entry(inode, name.encode(self.encoding))
 
-    def do_invalidations(self):
-        di = self.deferred_invalidations
-        self.deferred_invalidations = []
+    def clear(self):
+        self.inode_cache.clear()
+
+        for k,v in self._entries.items():
+            try:
+                v.finalize()
+            except Exception as e:
+                _logger.exception("Error during finalize of inode %i", k)
+
+        self._entries.clear()
 
-        with llfuse.lock_released:
-            for d in di:
-                if len(d) == 1:
-                    llfuse.invalidate_inode(d[0])
-                elif len(d) == 2:
-                    llfuse.invalidate_entry(d[0], d[1])
 
 def catch_exceptions(orig_func):
     """Catch uncaught exceptions and log them consistently."""
@@ -274,19 +279,18 @@ def catch_exceptions(orig_func):
             raise
         except EnvironmentError as e:
             raise llfuse.FUSEError(e.errno)
+        except arvados.errors.KeepWriteError as e:
+            _logger.error("Keep write error: " + str(e))
+            raise llfuse.FUSEError(errno.EIO)
+        except arvados.errors.NotFoundError as e:
+            _logger.error("Block not found error: " + str(e))
+            raise llfuse.FUSEError(errno.EIO)
         except:
             _logger.exception("Unhandled exception during FUSE operation")
             raise llfuse.FUSEError(errno.EIO)
 
     return catch_exceptions_wrapper
 
-def deferred_invalidate(orig_func):
-    @functools.wraps(orig_func)
-    def deferred_invalidate_wrapper(self, *args, **kwargs):
-        n = orig_func(self, *args, **kwargs)
-        self.inodes.do_invalidations()
-        return n
-    return deferred_invalidate_wrapper
 
 class Operations(llfuse.Operations):
     """This is the main interface with llfuse.
@@ -300,9 +304,11 @@ class Operations(llfuse.Operations):
 
     """
 
-    def __init__(self, uid, gid, encoding="utf-8", inode_cache=None, num_retries=4, enable_write=False):
+    def __init__(self, uid, gid, api_client, encoding="utf-8", inode_cache=None, num_retries=4, enable_write=False):
         super(Operations, self).__init__()
 
+        self._api_client = api_client
+
         if not inode_cache:
             inode_cache = InodeCache(cap=256*1024*1024)
         self.inodes = Inodes(inode_cache, encoding=encoding)
@@ -318,8 +324,19 @@ class Operations(llfuse.Operations):
         # is fully initialized should wait() on this event object.
         self.initlock = threading.Event()
 
+        # If we get overlapping shutdown events (e.g., fusermount -u
+        # -z and operations.destroy()) llfuse calls forget() on inodes
+        # that have already been deleted. To avoid this, we make
+        # forget() a no-op if called after destroy().
+        self._shutdown_started = threading.Event()
+
         self.num_retries = num_retries
 
+        self.read_counter = arvados.keep.Counter()
+        self.write_counter = arvados.keep.Counter()
+        self.read_ops_counter = arvados.keep.Counter()
+        self.write_ops_counter = arvados.keep.Counter()
+
         self.events = None
 
     def init(self):
@@ -329,53 +346,56 @@ class Operations(llfuse.Operations):
 
     @catch_exceptions
     def destroy(self):
-        if self.events:
-            self.events.close()
-            self.events = None
+        with llfuse.lock:
+            self._shutdown_started.set()
+            if self.events:
+                self.events.close()
+                self.events = None
 
-        for k,v in self.inodes.items():
-            v.finalize()
-        self.inodes = None
+            self.inodes.clear()
 
     def access(self, inode, mode, ctx):
         return True
 
-    def listen_for_events(self, api_client):
-        self.events = arvados.events.subscribe(api_client,
+    def listen_for_events(self):
+        self.events = arvados.events.subscribe(self._api_client,
                                  [["event_type", "in", ["create", "update", "delete"]]],
                                  self.on_event)
 
     @catch_exceptions
     def on_event(self, ev):
-        if 'event_type' in ev:
-            with llfuse.lock:
-                item = self.inodes.inode_cache.find(ev["object_uuid"])
-                if item is not None:
-                    item.invalidate()
-                    if ev["object_kind"] == "arvados#collection":
-                        new_attr = ev.get("properties") and ev["properties"].get("new_attributes") and ev["properties"]["new_attributes"]
-
-                        # new_attributes.modified_at currently lacks subsecond precision (see #6347) so use event_at which
-                        # should always be the same.
-                        #record_version = (new_attr["modified_at"], new_attr["portable_data_hash"]) if new_attr else None
-                        record_version = (ev["event_at"], new_attr["portable_data_hash"]) if new_attr else None
-
-                        item.update(to_record_version=record_version)
-                    else:
-                        item.update()
-
-                oldowner = ev.get("properties") and ev["properties"].get("old_attributes") and ev["properties"]["old_attributes"].get("owner_uuid")
-                olditemparent = self.inodes.inode_cache.find(oldowner)
-                if olditemparent is not None:
-                    olditemparent.invalidate()
-                    olditemparent.update()
-
-                itemparent = self.inodes.inode_cache.find(ev["object_owner_uuid"])
-                if itemparent is not None:
-                    itemparent.invalidate()
-                    itemparent.update()
-
-                self.inodes.do_invalidations()
+        if 'event_type' not in ev:
+            return
+        with llfuse.lock:
+            for item in self.inodes.inode_cache.find_by_uuid(ev["object_uuid"]):
+                item.invalidate()
+                if ev["object_kind"] == "arvados#collection":
+                    new_attr = (ev.get("properties") and
+                                ev["properties"].get("new_attributes") and
+                                ev["properties"]["new_attributes"])
+
+                    # new_attributes.modified_at currently lacks
+                    # subsecond precision (see #6347) so use event_at
+                    # which should always be the same.
+                    record_version = (
+                        (ev["event_at"], new_attr["portable_data_hash"])
+                        if new_attr else None)
+
+                    item.update(to_record_version=record_version)
+                else:
+                    item.update()
+
+            oldowner = (
+                ev.get("properties") and
+                ev["properties"].get("old_attributes") and
+                ev["properties"]["old_attributes"].get("owner_uuid"))
+            newowner = ev["object_owner_uuid"]
+            for parent in (
+                    self.inodes.inode_cache.find_by_uuid(oldowner) +
+                    self.inodes.inode_cache.find_by_uuid(newowner)):
+                parent.invalidate()
+                parent.update()
+
 
     @catch_exceptions
     def getattr(self, inode):
@@ -387,8 +407,8 @@ class Operations(llfuse.Operations):
         entry = llfuse.EntryAttributes()
         entry.st_ino = inode
         entry.generation = 0
-        entry.entry_timeout = 60
-        entry.attr_timeout = 60
+        entry.entry_timeout = 60 if e.allow_dirent_cache else 0
+        entry.attr_timeout = 60 if e.allow_attr_cache else 0
 
         entry.st_mode = stat.S_IRUSR | stat.S_IRGRP | stat.S_IROTH
         if isinstance(e, Directory):
@@ -408,8 +428,6 @@ class Operations(llfuse.Operations):
 
         entry.st_size = e.size()
 
-        _logger.debug("getattr got size")
-
         entry.st_blksize = 512
         entry.st_blocks = (entry.st_size/512)+1
         entry.st_atime = int(e.atime())
@@ -441,6 +459,7 @@ class Operations(llfuse.Operations):
         else:
             if parent_inode in self.inodes:
                 p = self.inodes[parent_inode]
+                self.inodes.touch(p)
                 if name == '..':
                     inode = p.parent_inode
                 elif isinstance(p, Directory) and name in p:
@@ -457,8 +476,9 @@ class Operations(llfuse.Operations):
             raise llfuse.FUSEError(errno.ENOENT)
 
     @catch_exceptions
-    @deferred_invalidate
     def forget(self, inodes):
+        if self._shutdown_started.is_set():
+            return
         for inode, nlookup in inodes:
             ent = self.inodes[inode]
             _logger.debug("arv-mount forget: inode %i nlookup %i ref_count %i", inode, nlookup, ent.ref_count)
@@ -481,11 +501,16 @@ class Operations(llfuse.Operations):
         fh = next(self._filehandles_counter)
         self._filehandles[fh] = FileHandle(fh, p)
         self.inodes.touch(p)
+
+        _logger.debug("arv-mount open inode %i flags %x fh %i", inode, flags, fh)
+
         return fh
 
     @catch_exceptions
     def read(self, fh, off, size):
-        _logger.debug("arv-mount read %i %i %i", fh, off, size)
+        _logger.debug("arv-mount read fh %i off %i size %i", fh, off, size)
+        self.read_ops_counter.add(1)
+
         if fh in self._filehandles:
             handle = self._filehandles[fh]
         else:
@@ -493,15 +518,16 @@ class Operations(llfuse.Operations):
 
         self.inodes.touch(handle.obj)
 
-        try:
-            return handle.obj.readfrom(off, size, self.num_retries)
-        except arvados.errors.NotFoundError as e:
-            _logger.error("Block not found: " + str(e))
-            raise llfuse.FUSEError(errno.EIO)
+        r = handle.obj.readfrom(off, size, self.num_retries)
+        if r:
+            self.read_counter.add(len(r))
+        return r
 
     @catch_exceptions
     def write(self, fh, off, buf):
         _logger.debug("arv-mount write %i %i %i", fh, off, len(buf))
+        self.write_ops_counter.add(1)
+
         if fh in self._filehandles:
             handle = self._filehandles[fh]
         else:
@@ -512,27 +538,27 @@ class Operations(llfuse.Operations):
 
         self.inodes.touch(handle.obj)
 
-        return handle.obj.writeto(off, buf, self.num_retries)
+        w = handle.obj.writeto(off, buf, self.num_retries)
+        if w:
+            self.write_counter.add(w)
+        return w
 
     @catch_exceptions
-    @deferred_invalidate
     def release(self, fh):
         if fh in self._filehandles:
             try:
                 self._filehandles[fh].flush()
-            except EnvironmentError as e:
-                raise llfuse.FUSEError(e.errno)
             except Exception:
-                _logger.exception("Flush error")
-            self._filehandles[fh].release()
-            del self._filehandles[fh]
+                raise
+            finally:
+                self._filehandles[fh].release()
+                del self._filehandles[fh]
         self.inodes.inode_cache.cap_cache()
 
     def releasedir(self, fh):
         self.release(fh)
 
     @catch_exceptions
-    @deferred_invalidate
     def opendir(self, inode):
         _logger.debug("arv-mount opendir: inode %i", inode)
 
@@ -565,8 +591,6 @@ class Operations(llfuse.Operations):
         else:
             raise llfuse.FUSEError(errno.EBADF)
 
-        _logger.debug("arv-mount handle.dirobj %s", handle.obj)
-
         e = off
         while e < len(handle.entries):
             if handle.entries[e][1].inode in self.inodes:
@@ -607,7 +631,6 @@ class Operations(llfuse.Operations):
         return p
 
     @catch_exceptions
-    @deferred_invalidate
     def create(self, inode_parent, name, mode, flags, ctx):
         _logger.debug("arv-mount create: %i '%s' %o", inode_parent, name, mode)
 
@@ -624,7 +647,6 @@ class Operations(llfuse.Operations):
         return (fh, self.getattr(f.inode))
 
     @catch_exceptions
-    @deferred_invalidate
     def mkdir(self, inode_parent, name, mode, ctx):
         _logger.debug("arv-mount mkdir: %i '%s' %o", inode_parent, name, mode)
 
@@ -638,21 +660,18 @@ class Operations(llfuse.Operations):
         return self.getattr(d.inode)
 
     @catch_exceptions
-    @deferred_invalidate
     def unlink(self, inode_parent, name):
         _logger.debug("arv-mount unlink: %i '%s'", inode_parent, name)
         p = self._check_writable(inode_parent)
         p.unlink(name)
 
     @catch_exceptions
-    @deferred_invalidate
     def rmdir(self, inode_parent, name):
         _logger.debug("arv-mount rmdir: %i '%s'", inode_parent, name)
         p = self._check_writable(inode_parent)
         p.rmdir(name)
 
     @catch_exceptions
-    @deferred_invalidate
     def rename(self, inode_parent_old, name_old, inode_parent_new, name_new):
         _logger.debug("arv-mount rename: %i '%s' %i '%s'", inode_parent_old, name_old, inode_parent_new, name_new)
         src = self._check_writable(inode_parent_old)
@@ -660,7 +679,6 @@ class Operations(llfuse.Operations):
         dest.rename(name_old, name_new, src)
 
     @catch_exceptions
-    @deferred_invalidate
     def flush(self, fh):
         if fh in self._filehandles:
             self._filehandles[fh].flush()