6643: Add test case that reproduces the bug

diff --git a/services/fuse/arvados_fuse/__init__.py b/services/fuse/arvados_fuse/__init__.py
index b24aaa6d3d08c2e470ac3fbb2cb47999e882a53b..59b4a6219233e1b857b96081950d6a71865e5ac5 100644 (file)
--- a/services/fuse/arvados_fuse/__init__.py
+++ b/services/fuse/arvados_fuse/__init__.py
@@ -170,7 +170,7 @@ class InodeCache(object):
             if obj.cache_uuid:
                 self._by_uuid[obj.cache_uuid] = 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

diff --git a/services/fuse/arvados_fuse/fusedir.py b/services/fuse/arvados_fuse/fusedir.py
index 16b3bb2cdb53c80a40166bea4b6ab4e816435a90..5ebb6b94ae42a21ec24bf78ccfedaecd00ff3cbe 100644 (file)
--- a/services/fuse/arvados_fuse/fusedir.py
+++ b/services/fuse/arvados_fuse/fusedir.py
@@ -423,8 +423,8 @@ class CollectionDirectory(CollectionDirectoryBase):
                 return True
             finally:
                 self._updating_lock.release()
-        except arvados.errors.NotFoundError:
-            _logger.exception("arv-mount %s: error", self.collection_locator)
+        except arvados.errors.NotFoundError as e:
+            _logger.error("Error fetching collection '%s': %s", self.collection_locator, e)
         except arvados.errors.ArgumentError as detail:
             _logger.warning("arv-mount %s: error %s", self.collection_locator, detail)
             if self.collection_record is not None and "manifest_text" in self.collection_record:
@@ -527,6 +527,7 @@ will appear if it exists.
                 self._entries[k] = e
                 return True
             else:
+                _logger.debug('update failed of %s', k)
                 return False
         except Exception as e:
             _logger.debug('arv-mount exception keep %s', e)

diff --git a/services/fuse/tests/mount_test_base.py b/services/fuse/tests/mount_test_base.py
index ab623c39c017f7d9c7117fb0aa766f65945c22eb..3b7cbaaadb0a8ab9c490c1a73a1648b54d89728c 100644 (file)
--- a/services/fuse/tests/mount_test_base.py
+++ b/services/fuse/tests/mount_test_base.py
@@ -17,7 +17,7 @@ import run_test_server
 logger = logging.getLogger('arvados.arv-mount')
 
 class MountTestBase(unittest.TestCase):
-    def setUp(self):
+    def setUp(self, api=None):
         # The underlying C implementation of open() makes a fstat() syscall
         # with the GIL still held.  When the GETATTR message comes back to
         # llfuse (which in these tests is in the same interpreter process) it
@@ -32,7 +32,7 @@ class MountTestBase(unittest.TestCase):
         self.mounttmp = tempfile.mkdtemp()
         run_test_server.run()
         run_test_server.authorize_with("admin")
-        self.api = arvados.safeapi.ThreadSafeApiCache(arvados.config.settings())
+        self.api = api if api else arvados.safeapi.ThreadSafeApiCache(arvados.config.settings())
 
     def make_mount(self, root_class, **root_kwargs):
         self.operations = fuse.Operations(os.getuid(), os.getgid(), enable_write=True)

diff --git a/services/fuse/tests/test_mount.py b/services/fuse/tests/test_mount.py
index 5e818cc49e1998ce69e3739e22ee7890f7b55e5b..53bde6e863af571cb2b8a0f4c4cab2f8b53878b7 100644 (file)
--- a/services/fuse/tests/test_mount.py
+++ b/services/fuse/tests/test_mount.py
@@ -15,6 +15,7 @@ import unittest
 import logging
 import multiprocessing
 import run_test_server
+import mock
 
 from mount_test_base import MountTestBase
 
@@ -110,8 +111,8 @@ class FuseNoAPITest(MountTestBase):
 
 
 class FuseMagicTest(MountTestBase):
-    def setUp(self):
-        super(FuseMagicTest, self).setUp()
+    def setUp(self, api=None):
+        super(FuseMagicTest, self).setUp(api=api)
 
         cw = arvados.CollectionWriter()
 
@@ -119,7 +120,8 @@ class FuseMagicTest(MountTestBase):
         cw.write("data 1")
 
         self.testcollection = cw.finish()
-        self.api.collections().create(body={"manifest_text":cw.manifest_text()}).execute()
+        self.test_manifest = cw.manifest_text()
+        self.api.collections().create(body={"manifest_text":self.test_manifest}).execute()
 
     def runTest(self):
         self.make_mount(fuse.MagicDirectory)
@@ -1009,6 +1011,24 @@ class FuseFsyncTest(FuseMagicTest):
         self.pool.apply(fuseFsyncTestHelper, (self.mounttmp, self.testcollection))
 
 
+class MagicDirApiError(FuseMagicTest):
+    def setUp(self):
+        api = mock.MagicMock()
+        super(MagicDirApiError, self).setUp(api=api)
+        api.collections().get().execute.side_effect = iter([Exception('API fail'), {"manifest_text": self.test_manifest}])
+        api.keep.get.side_effect = Exception('Keep fail')
+
+    def runTest(self):
+        self.make_mount(fuse.MagicDirectory)
+
+        self.operations.inodes.inode_cache.cap = 1
+        self.operations.inodes.inode_cache.min_entries = 1
+
+        with self.assertRaises(OSError):
+            llfuse.listdir(os.path.join(self.mounttmp, self.testcollection))
+
+        llfuse.listdir(os.path.join(self.mounttmp, self.testcollection))
+
 class FuseUnitTest(unittest.TestCase):
     def test_sanitize_filename(self):
         acceptable = [