Unhandled INotify event from eCryptFs breaks syncdaemon

[Roman Yepishev]

I found this with ecryptfs folder, looks like it is possible to reproduce only with it

STR:

0. set up ecryptfs folder
1. u1sdtool --create-folder=$HOME/.Private
2. u1sdtool --quit; u1sdtool --start
3. ls -l ~/.Private
4. touch ~/Ubuntu\ One/somefile.txt

Expected results:
somefile.txt appears online

Actual results:
2011-10-12 16:42:54,569 - ubuntuone.SyncDaemon.filesystem_notifications.GeneralProcessor - ERROR - Unhandled Event in INotify: <Event dir=True mask=0x40000008 maskname=IN_CLOSE_WRITE
|IN_ISDIR name='' path=/home/rtg/.Private pathname=/home/rtg/.Private wd=8 >
2011-10-12 16:42:54,702 - twisted - ERROR - Unhandled Error
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/twisted/python/log.py", line 84, in callWithLogger
    return callWithContext({"system": lp}, func, *args, **kw)
  File "/usr/lib/python2.7/dist-packages/twisted/python/log.py", line 69, in callWithContext
    return context.call({ILogContext: newCtx}, func, *args, **kw)
  File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 118, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 81, in callWithContext
    return func(*args,**kw)
--- <exception caught here> ---
  File "/usr/lib/python2.7/dist-packages/twisted/internet/gtk2reactor.py", line 288, in _doReadOrWrite
    why = source.doRead()
  File "/usr/lib/python2.7/dist-packages/ubuntuone-client/ubuntuone/platform/linux/filesystem_notifications.py", line 422, in doRead
    notifier.process_events()
  File "/usr/lib/python2.7/dist-packages/pyinotify.py", line 1197, in process_events
    self._default_proc_fun(revent)
  File "/usr/lib/python2.7/dist-packages/pyinotify.py", line 840, in __call__
    return _ProcessEvent.__call__(self, event)
  File "/usr/lib/python2.7/dist-packages/pyinotify.py", line 577, in __call__
    return self.process_default(event)
  File "/usr/lib/python2.7/dist-packages/ubuntuone-client/ubuntuone/platform/linux/filesystem_notifications.py", line 78, in func
    real_func(self, event)
  File "/usr/lib/python2.7/dist-packages/ubuntuone-client/ubuntuone/platform/linux/filesystem_notifications.py", line 319, in process_default
    self.general_processor.push_event(event)
  File "/usr/lib/python2.7/dist-packages/ubuntuone-client/ubuntuone/syncdaemon/filesystem_notifications.py", line 142, in push_event
    raise KeyError("Unhandled Event in INotify: %s" % event)
exceptions.KeyError: "Unhandled Event in INotify: <Event dir=True mask=0x40000008 maskname=IN_CLOSE_WRITE|IN_ISDIR name='' path=/home/rtg/.Private pathname=/home/rtg/.Private wd=8 >"

SD receives event it does not know how to handle and stops reacting on any inotify events. The bug about IN_CLOSE_WRITE|IN_ISDIR specifically is LP:TBD

ProblemType: Bug
DistroRelease: Ubuntu 11.10
Package: ubuntuone-client 2.0.0-0ubuntu2
ProcVersionSignature: Ubuntu 3.0.0-12.20-generic 3.0.4
Uname: Linux 3.0.0-12-generic x86_64
NonfreeKernelModules: nvidia
ApportVersion: 1.23-0ubuntu3
Architecture: amd64
Date: Wed Oct 12 17:16:16 2011
EcryptfsInUse: Yes
InstallationMedia: Ubuntu 10.04 LTS "Lucid Lynx" - Release amd64 (20100429)
PackageArchitecture: all
SourcePackage: ubuntuone-client
UbuntuOneSyncdaemonExceptionsLog:

UpgradeStatus: Upgraded to oneiric on 2011-08-30 (43 days ago)

[Roman Yepishev (rye)]

The easiest fix is to make sure IN_CLOSE_WRITE is processed only on directories.

    @validate_filename
    def process_IN_CLOSE_WRITE(self, event):
        """Ecryptfs sends this inotify event for lower directories."""
        if not (event.mask & pyinotify.IN_ISDIR):
            self.general_processor.push_event(event)

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Roman Yepishev (rye)]

Facundo, is it correct that this code has no exception handler:

def _hook_inotify_to_twisted(self, wm, notifier):
    """This will hook inotify to twisted."""

    class MyReader(abstract.FileDescriptor):
        """Chain between inotify and twisted."""
        # will never pass a fd to write, pylint: disable-msg=W0223

        def fileno(self):
            """Returns the fileno to select()."""
            # pylint: disable-msg=W0212
            return wm._fd

        def doRead(self):
            """Called when twisted says there's something to read."""
            notifier.read_events()
            notifier.process_events()

    reader = MyReader()
    reactor.addReader(reader)
    return reader

In case when process__events() fails, then all subsequent INotify events are not processed.

[Facundo Batista (facundo)]

Yes!

Proposed patch (needs tests):

=== modified file 'ubuntuone/platform/linux/filesystem_notifications.py'
--- ubuntuone/platform/linux/filesystem_notifications.py 2011-10-18 13:51:26 +0000
+++ ubuntuone/platform/linux/filesystem_notifications.py 2011-12-19 11:23:11 +0000
@@ -405,6 +405,7 @@

     def _hook_inotify_to_twisted(self, wm, notifier):
         """This will hook inotify to twisted."""
+ _logger = self.log

         class MyReader(abstract.FileDescriptor):
             """Chain between inotify and twisted."""
@@ -418,7 +419,10 @@
             def doRead(self):
                 """Called when twisted says there's something to read."""
                 notifier.read_events()
- notifier.process_events()
+ try:
+ notifier.process_events()
+ except Exception, e:
+ _logger.exception("Error while processing events: %r", e)

         reader = MyReader()
         reactor.addReader(reader)

[Facundo Batista (facundo)]

Bah, attached for readability

[Ubuntu Foundations Team Bug Bot (crichton)]

The attachment "notif.patch" of this bug report has been identified as being a patch. The ubuntu-reviewers team has been subscribed to the bug report so that they can review the patch. In the event that this is in fact not a patch you can resolve this situation by removing the tag 'patch' from the bug report and editing the attachment so that it is not flagged as a patch. Additionally, if you are member of the ubuntu-reviewers team please also unsubscribe the team from this bug report.

[This is an automated message performed by a Launchpad user owned by Brian Murray. Please contact him regarding any issues with the action taken in this bug report.]

[Roman Yepishev (rye)]

How can we make a test for this?

[Launchpad Janitor (janitor)]

This bug was fixed in the package ubuntuone-client - 3.99.0-0ubuntu1

---------------
ubuntuone-client (3.99.0-0ubuntu1) quantal; urgency=low

  * New upstream release.
    - Use dbus.Dictionary to pass empty dicts. (LP: #711162)
    - Ignore IN_CLOSE_WRITE for directories. (LP: #872894)
    - Validate SSL certificates better. (LP: #882062, LP: #1014654)
    - Ignore .goutputstream temporary flies. (LP: #1012620)
    - Handle failures better in share creation. (LP: #1013180)
    - Re-upload files when server reports empty hash. (LP: #1013401)
  * debian/control:
    - Update some build dependencies in preparation for testing during builds,
      and to allow building on older supported versions of Ubuntu.
  * debian/watch:
    - Update to use stable-4-0 series for Quantal releases.
 -- Rodney Dawes <email address hidden> Tue, 19 Jun 2012 16:58:05 -0400

[Brian Murray (brian-murray)]

Hello Roman, or anyone else affected,

Accepted ubuntuone-client into precise-proposed. The package will build now and be available at http://launchpad.net/ubuntu/+source/ubuntuone-client/3.0.2-0ubuntu1 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please change the bug tag from verification-needed to verification-done. If it does not, change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

[Launchpad Janitor (janitor)]

This bug was fixed in the package ubuntuone-client - 3.0.2-0ubuntu1

---------------
ubuntuone-client (3.0.2-0ubuntu1) precise-proposed; urgency=low

  * New upstream release. (LP: #1018991)
    - Wrap empty dicts with dbus.Dictionary. (LP: #711162)
    - Ignore IN_CLOSE_WRITE for directories. (LP: #872894)
    - Ignore .goutputstream temporary flies. (LP: #1012620)
    - Handle failures better in share creation. (LP: #1013180)
  * debian/copyright:
    - Remove comma in list of files for dep5 copyright format.
  * 00_bzr1259_lp1013401_reupload.patch:
    - Re-upload files when server reports empty hash. (LP: #1013401)
  * debian/patches:
    - Remove upstreamed patches.
 -- Rodney Dawes <email address hidden> Mon, 09 Jul 2012 15:46:44 -0400