Merge lp:~facundo/ubuntuone-client/ignore-nonutf8-filenames into lp:ubuntuone-client

[Facundo Batista]

Ignore all the events from disk when file/dir name is not valid.

Ignore all the events from disk when file/dir name is not valid.

This introduces a new event, FS_INVALID_NAME, and a new specific log to include only alerts when this happens (which are also logged in main log file).

Also, when this event happens, the DBus interface generates a signal to make the system aware of this.

Tests included for everything.

[lp:~facundo/ubuntuone-client/ignore-nonutf8-filenames]

450. By Facundo Batista on 2010-03-26

Docstring

[Natalia Bidart (nataliabidart)]

Nice!

review: Approve

[dobey (dobey)]

review: Approve

=== modified file 'data/source_ubuntuone-client.py'
--- data/source_ubuntuone-client.py	2009-10-06 13:50:37 +0000
+++ data/source_ubuntuone-client.py	2010-03-26 18:31:32 +0000
@@ -27,6 +27,7 @@
 # things we may want to collect for the report
 u1_client_log = os.path.join(u1_log_path, "syncdaemon.log")
 u1_except_log = os.path.join(u1_log_path, "syncdaemon-exceptions.log")
+u1_invalidnames_log = os.path.join(u1_log_path, "syncdaemon-invalid-names.log")
 u1_oauth_log = os.path.join(u1_log_path, "oauth-login.log")
 u1_u1sync_log = os.path.join(u1_log_path, "u1sync.log")
 u1_sd_conf = os.path.join("etc", "xdg", "ubuntuone", "syncdaemon.conf")
@@ -37,6 +38,7 @@
 def add_info(report):
     """add report info"""
     attach_file_if_exists(report, u1_except_log)
+    attach_file_if_exists(report, u1_invalidnames_log)
     attach_file_if_exists(report, u1_oauth_log)
     attach_file_if_exists(report, u1_usersd_conf)
     attach_file_if_exists(report, u1_sd_conf)

=== modified file 'tests/syncdaemon/test_dbus.py'
--- tests/syncdaemon/test_dbus.py	2010-03-10 22:12:06 +0000
+++ tests/syncdaemon/test_dbus.py	2010-03-26 18:31:32 +0000
@@ -1133,6 +1133,23 @@
             self.event_q.push(event_name, *args)
         return d
 
+    def test_invalid_filename(self):
+        """Test the FS_INVALID_NAME signal."""
+        d = defer.Deferred()
+
+        def handler(dirname, filename):
+            """Handler for InvalidName signal."""
+            self.assertTrue(isinstance(dirname, unicode))
+            self.assertTrue(isinstance(filename, str))
+            d.callback(True)
+
+        match = self.bus.add_signal_receiver(handler,
+                                             signal_name='InvalidName',
+                                             byte_arrays=True)
+        self.signal_receivers.add(match)
+        self.main.event_q.push('FS_INVALID_NAME', u'test/dir', 'testpath')
+        return d
+
     def test_share_changed(self):
         """ Test the ShareChanged signal. """
         share_path = os.path.join(self.main.shares_dir, 'share')

=== modified file 'tests/syncdaemon/test_eq_inotify.py'
--- tests/syncdaemon/test_eq_inotify.py	2010-03-15 17:05:49 +0000
+++ tests/syncdaemon/test_eq_inotify.py	2010-03-26 18:31:32 +0000
@@ -31,6 +31,18 @@
 from tests.syncdaemon.test_eventqueue import BaseEQTestCase
 
 
+class DontHitMe(object):
+    """We shouldn't be called."""
+
+    def __init__(self, test_instance):
+        self.test_instance = test_instance
+
+    def handle_default(self, *a, **k):
+        """Something here? Error!"""
+        self.test_inst.finished_error("Don't hit me! Received %s %s" % (a, k))
+
+
+
 class WatchTests(BaseEQTestCase):
     """Test the EQ API to add and remove watchs."""
 
@@ -393,20 +405,13 @@
         open(fromfile, "w").close()
         symlpath = os.path.join(testdir, "syml")
 
-        class DontHitMe(object):
-            """we shouldn't be called"""
-            # class-closure, cannot use self, pylint: disable-msg=E0213
-            def handle_default(innerself, *a):
-                """Something here? Error!"""
-                self.finished_error("don't hit me! received %s" % (a,))
-
         def confirm():
             """check result."""
             self.finished_ok()
 
         # set up everything and freeze
         self.eq.inotify_add_watch(testdir)
-        self.eq.subscribe(DontHitMe())
+        self.eq.subscribe(DontHitMe(self))
 
         os.symlink(fromfile, symlpath)
         reactor.callLater(.1, confirm)
@@ -1026,13 +1031,6 @@
         testfile = os.path.join(testdir, "bar")
         os.mkdir(testdir)
 
-        class DontHitMe(object):
-            """we shouldn't be called"""
-            # class-closure, cannot use self, pylint: disable-msg=E0213
-            def handle_default(innerself, *a):
-                """Something here? Error!"""
-                self.finished_error("don't hit me! received %s" % (a,))
-
         def freeze_commit():
             """release and check result."""
             d = self.eq.freeze_commit([("FS_DIR_DELETE", "foobar")])
@@ -1046,7 +1044,7 @@
 
         # set up everything and freeze
         self.eq.inotify_add_watch(testdir)
-        self.eq.subscribe(DontHitMe())
+        self.eq.subscribe(DontHitMe(self))
         self.eq.freeze_begin(testdir)
 
         open(testfile, "w").close()
@@ -1132,15 +1130,6 @@
 class MutedSignalsTests(BaseTwisted):
     """Test that EQ filter some signals on demand."""
 
-    class DontHitMe(object):
-        """we shouldn't be called"""
-        # class-closure, cannot use self, pylint: disable-msg=E0213
-        def __init__(innerself, obj):
-            innerself.obj = obj
-        def handle_default(innerself, *a):
-            """Something here? Error!"""
-            innerself.obj.finished_error("don't hit me! received %s" % (a,))
-
     def check_filter(self, _=None):
         self.assertFalse(self.eq._processor._to_mute._cnt)
         self.finished_ok()
@@ -1179,7 +1168,7 @@
         self.eq.add_to_mute_filter("FS_FILE_CLOSE_NOWRITE", testfile)
 
         self.eq.inotify_add_watch(self.root_dir)
-        self.eq.subscribe(self.DontHitMe(self))
+        self.eq.subscribe(DontHitMe(self))
 
         # generate the event
         open(testfile)
@@ -1194,7 +1183,7 @@
         self.eq.add_to_mute_filter("FS_FILE_CLOSE_NOWRITE", testfile)
 
         self.eq.inotify_add_watch(self.root_dir)
-        self.eq.subscribe(self.DontHitMe(self))
+        self.eq.subscribe(DontHitMe(self))
 
         # generate the event
         fh.close()
@@ -1209,7 +1198,7 @@
         self.eq.add_to_mute_filter("FS_FILE_CLOSE_WRITE", testfile)
 
         self.eq.inotify_add_watch(self.root_dir)
-        self.eq.subscribe(self.DontHitMe(self))
+        self.eq.subscribe(DontHitMe(self))
 
         # generate the event
         open(testfile, "w").close()
@@ -1222,7 +1211,7 @@
         self.eq.add_to_mute_filter("FS_DIR_CREATE", testdir)
 
         self.eq.inotify_add_watch(self.root_dir)
-        self.eq.subscribe(self.DontHitMe(self))
+        self.eq.subscribe(DontHitMe(self))
 
         # generate the event
         os.mkdir(testdir)
@@ -1236,7 +1225,7 @@
         self.eq.add_to_mute_filter("FS_FILE_DELETE", testfile)
 
         self.eq.inotify_add_watch(self.root_dir)
-        self.eq.subscribe(self.DontHitMe(self))
+        self.eq.subscribe(DontHitMe(self))
 
         # generate the event
         os.remove(testfile)
@@ -1250,7 +1239,7 @@
         self.eq.add_to_mute_filter("FS_DIR_DELETE", testdir)
 
         self.eq.inotify_add_watch(self.root_dir)
-        self.eq.subscribe(self.DontHitMe(self))
+        self.eq.subscribe(DontHitMe(self))
 
         # generate the event
         os.rmdir(testdir)
@@ -1269,7 +1258,7 @@
         self.eq.add_to_mute_filter("FS_FILE_MOVE", fromfile, tofile)
 
         self.eq.inotify_add_watch(self.root_dir)
-        self.eq.subscribe(self.DontHitMe(self))
+        self.eq.subscribe(DontHitMe(self))
 
         # generate the event
         os.rename(fromfile, tofile)
@@ -1288,7 +1277,7 @@
         self.eq.add_to_mute_filter("FS_DIR_MOVE", fromdir, todir)
 
         self.eq.inotify_add_watch(self.root_dir)
-        self.eq.subscribe(self.DontHitMe(self))
+        self.eq.subscribe(DontHitMe(self))
 
         # generate the event
         os.rename(fromdir, todir)
@@ -1307,7 +1296,7 @@
         self.eq.add_to_mute_filter("FS_FILE_MOVE", fromfile, tofile)
 
         self.eq.inotify_add_watch(self.root_dir)
-        self.eq.subscribe(self.DontHitMe(self))
+        self.eq.subscribe(DontHitMe(self))
 
         # generate the event
         os.rename(fromfile, tofile)
@@ -1325,7 +1314,7 @@
         self.eq.add_to_mute_filter("FS_FILE_CLOSE_WRITE", tofile)
 
         self.eq.inotify_add_watch(root_dir)
-        self.eq.subscribe(self.DontHitMe(self))
+        self.eq.subscribe(DontHitMe(self))
 
         # generate the event
         os.rename(fromfile, tofile)
@@ -1727,6 +1716,140 @@
         return self._deferred
 
 
+class NonUTF8NamesTests(BaseTwisted):
+    """Test the non-utf8 name handling."""
+
+    invalid_name = "invalid \xff\xff name"
+
+    def test_file_open(self):
+        """Test invalid_filename after open a file."""
+        testfile = os.path.join(self.root_dir, self.invalid_name)
+        open(testfile, "w").close()
+
+        self.eq.inotify_add_watch(self.root_dir)
+        should_events = [
+            ('FS_INVALID_NAME', self.root_dir, self.invalid_name), # open
+            ('FS_INVALID_NAME', self.root_dir, self.invalid_name), # close no w
+        ]
+        self.eq.subscribe(DynamicHitMe(should_events, self))
+
+        # generate the event
+        open(testfile)
+        return self._deferred
+
+    def test_file_close_nowrite(self):
+        """Test invalid_filename after a close no write."""
+        testfile = os.path.join(self.root_dir, self.invalid_name)
+        open(testfile, "w").close()
+        fh = open(testfile)
+
+        self.eq.inotify_add_watch(self.root_dir)
+        should_events = [
+            ('FS_INVALID_NAME', self.root_dir, self.invalid_name), # close no w
+        ]
+        self.eq.subscribe(DynamicHitMe(should_events, self))
+
+        # generate the event
+        fh.close()
+        return self._deferred
+
+    def test_file_create_close_write(self):
+        """Test invalid_filename after a create, open and close write."""
+        testfile = os.path.join(self.root_dir, self.invalid_name)
+
+        self.eq.inotify_add_watch(self.root_dir)
+        should_events = [
+            ('FS_INVALID_NAME', self.root_dir, self.invalid_name), # create
+            ('FS_INVALID_NAME', self.root_dir, self.invalid_name), # open
+            ('FS_INVALID_NAME', self.root_dir, self.invalid_name), # close w
+        ]
+        self.eq.subscribe(DynamicHitMe(should_events, self))
+
+        # generate the event
+        open(testfile, "w").close()
+        return self._deferred
+
+    def test_dir_create(self):
+        """Test invalid_filename after a dir create."""
+        testdir = os.path.join(self.root_dir, self.invalid_name)
+
+        self.eq.inotify_add_watch(self.root_dir)
+        should_events = [
+            ('FS_INVALID_NAME', self.root_dir, self.invalid_name), # create
+        ]
+        self.eq.subscribe(DynamicHitMe(should_events, self))
+
+        # generate the event
+        os.mkdir(testdir)
+        return self._deferred
+
+    def test_file_delete(self):
+        """Test invalid_filename after a file delete."""
+        testfile = os.path.join(self.root_dir, self.invalid_name)
+        open(testfile, "w").close()
+
+        self.eq.inotify_add_watch(self.root_dir)
+        should_events = [
+            ('FS_INVALID_NAME', self.root_dir, self.invalid_name), # delete
+        ]
+        self.eq.subscribe(DynamicHitMe(should_events, self))
+
+        # generate the event
+        os.remove(testfile)
+        return self._deferred
+
+    def test_dir_delete(self):
+        """Test invalid_filename after a dir delete."""
+        testdir = os.path.join(self.root_dir, self.invalid_name)
+        os.mkdir(testdir)
+
+        self.eq.inotify_add_watch(self.root_dir)
+        should_events = [
+            ('FS_INVALID_NAME', self.root_dir, self.invalid_name), # delete
+        ]
+        self.eq.subscribe(DynamicHitMe(should_events, self))
+
+        # generate the event
+        os.rmdir(testdir)
+        return self._deferred
+
+    def test_file_move_to(self):
+        """Test invalid_filename after moving a file into a watched dir."""
+        fromfile = os.path.join(self.root_dir, self.invalid_name)
+        open(fromfile, "w").close()
+        destdir = os.path.join(self.root_dir, "watched_dir")
+        os.mkdir(destdir)
+        destfile = os.path.join(destdir, self.invalid_name)
+
+        self.eq.inotify_add_watch(destdir)
+        should_events = [
+            ('FS_INVALID_NAME', destdir, self.invalid_name), # move to
+        ]
+        self.eq.subscribe(DynamicHitMe(should_events, self))
+
+        # generate the event
+        os.rename(fromfile, destfile)
+        return self._deferred
+
+    def test_file_move_from(self):
+        """Test invalid_filename after moving a file from a watched dir."""
+        fromdir = os.path.join(self.root_dir, "watched_dir")
+        os.mkdir(fromdir)
+        fromfile = os.path.join(fromdir, self.invalid_name)
+        open(fromfile, "w").close()
+        destfile = os.path.join(self.root_dir, self.invalid_name)
+
+        self.eq.inotify_add_watch(fromdir)
+        should_events = [
+            ('FS_INVALID_NAME', fromdir, self.invalid_name), # move from
+        ]
+        self.eq.subscribe(DynamicHitMe(should_events, self))
+
+        # generate the event
+        os.rename(fromfile, destfile)
+        return self._deferred
+
+
 def test_suite():
     # pylint: disable-msg=C0111
     return unittest.TestLoader().loadTestsFromName(__name__)

=== modified file 'ubuntuone/syncdaemon/dbus_interface.py'
--- ubuntuone/syncdaemon/dbus_interface.py	2010-03-23 22:48:19 +0000
+++ ubuntuone/syncdaemon/dbus_interface.py	2010-03-26 18:31:32 +0000
@@ -285,6 +285,11 @@
         """ Fire a D-BUS signal, notifying an upload has finished.  """
         pass
 
+    @dbus.service.signal(DBUS_IFACE_STATUS_NAME, signature='say')
+    def InvalidName(self, dirname, filename):
+        """Fire a D-BUS signal, notifying an invalid file or dir name."""
+        pass
+
     @dbus.service.signal(DBUS_IFACE_STATUS_NAME)
     def StatusChanged(self, status):
         """ Fire a D-BUS signal, notifying that the status of the
@@ -333,6 +338,10 @@
                            'size': '0'}
         self.ContentQueueChanged(message)
 
+    def emit_invalid_name(self, dirname, filename):
+        """Emits the signal."""
+        self.InvalidName(unicode(dirname), str(filename))
+
     def emit_status_changed(self, state):
         """Emits the signal."""
         state_dict = {'name':state.name,
@@ -551,6 +560,11 @@
                         upload_error=str(error))
             self.dbus_iface.status.emit_signal_error('UploadFinished', args)
 
+    def handle_FS_INVALID_NAME(self, dirname, filename):
+        """Handle FS_INVALID_NAME."""
+        self.handle_default('FS_INVALID_NAME', dirname, filename)
+        self.dbus_iface.status.emit_invalid_name(dirname, filename)
+
     def handle_SYS_STATE_CHANGED(self, state):
         """ handle SYS_STATE_CHANGED """
         self.handle_default('SYS_STATE_CHANGED', state)

=== modified file 'ubuntuone/syncdaemon/event_queue.py'
--- ubuntuone/syncdaemon/event_queue.py	2010-03-24 12:44:39 +0000
+++ ubuntuone/syncdaemon/event_queue.py	2010-03-26 18:31:32 +0000
@@ -41,6 +41,7 @@
     'FS_DIR_DELETE': ('path',),
     'FS_FILE_MOVE': ('path_from', 'path_to',),
     'FS_DIR_MOVE': ('path_from', 'path_to',),
+    'FS_INVALID_NAME': ('dirname', 'filename',),
 
     'AQ_FILE_NEW_OK': ('marker', 'new_id'),
     'AQ_FILE_NEW_ERROR': ('marker', 'error'),
@@ -184,6 +185,23 @@
 DEFAULT_HANDLER = "handle_default" # receives (event_name, *args, **kwargs)
 
 
+def validate_filename(real_func):
+    """Decorator that validates the filename."""
+    def func(self, event):
+        """If valid, executes original function."""
+        try:
+            # validate UTF-8
+            event.name.decode("utf8")
+        except UnicodeDecodeError:
+            dirname = event.path.decode("utf8")
+            self.invnames_log.info("%s in %r: path %r", event.maskname,
+                                   dirname, event.name)
+            self.eq.push('FS_INVALID_NAME', dirname, event.name)
+        else:
+            real_func(self, event)
+    return func
+
+
 class MuteFilter(object):
     """Stores what needs to be muted."""
     def __init__(self):
@@ -294,6 +312,8 @@
     """
     def __init__(self, eq, ignore_config=None):
         self.log = logging.getLogger('ubuntuone.SyncDaemon.GeneralINotProc')
+        self.invnames_log = logging.getLogger(
+                                        'ubuntuone.SyncDaemon.InvalidNames')
         self.eq = eq
         self.held_event = None
         self.timer = None
@@ -351,11 +371,13 @@
         self.push_event(self.held_event)
         self.held_event = None
 
+    @validate_filename
     def process_IN_OPEN(self, event):
         """Filter IN_OPEN to make it happen only in files."""
         if not (event.mask & evtcodes.IN_ISDIR):
             self.push_event(event)
 
+    @validate_filename
     def process_IN_CLOSE_NOWRITE(self, event):
         """Filter IN_CLOSE_NOWRITE to make it happen only in files."""
         if not (event.mask & evtcodes.IN_ISDIR):
@@ -369,6 +391,7 @@
 
         """
 
+    @validate_filename
     def process_IN_MOVED_FROM(self, event):
         """Capture the MOVED_FROM to maybe syntethize FILE_MOVED."""
         if self.held_event is not None:
@@ -409,6 +432,7 @@
 
         return False
 
+    @validate_filename
     def process_IN_MOVED_TO(self, event):
         """Capture the MOVED_TO to maybe syntethize FILE_MOVED."""
         if self.held_event is not None:
@@ -476,6 +500,7 @@
         if not self._to_mute.pop(event_data):
             self.eq.push(*event_data)
 
+    @validate_filename
     def process_default(self, event):
         """Push the event into the EventQueue."""
         if self.held_event is not None:

=== modified file 'ubuntuone/syncdaemon/logger.py'
--- ubuntuone/syncdaemon/logger.py	2010-02-15 17:19:53 +0000
+++ ubuntuone/syncdaemon/logger.py	2010-03-26 18:31:32 +0000
@@ -334,6 +334,7 @@
 
 LOGFILENAME = os.path.join(LOGFOLDER, 'syncdaemon.log')
 EXLOGFILENAME = os.path.join(LOGFOLDER, 'syncdaemon-exceptions.log')
+INVALIDLOGFILENAME = os.path.join(LOGFOLDER, 'syncdaemon-invalid-names.log')
 
 LOGBACKUP = 5 # the number of log files to keep around
 
@@ -397,6 +398,14 @@
 inotify_logger.setLevel(logging.ERROR)
 inotify_logger.propagate = False
 
+# invalid filenames log
+invnames_logger = logging.getLogger("ubuntuone.SyncDaemon.InvalidNames")
+invnames_logger.setLevel(_DEBUG_LOG_LEVEL)
+invnames_handler = CustomRotatingFileHandler(filename=INVALIDLOGFILENAME)
+invnames_handler.setFormatter(basic_formatter)
+invnames_handler.setLevel(logging.INFO)
+invnames_logger.addHandler(invnames_handler)
+
 
 def configure_logging(level, maxBytes, backupCount):
     """configure level, maxBytes and backupCount in all handlers"""