From bda7301cb84a527b75f2be7e573cd6f7877a65e0 Mon Sep 17 00:00:00 2001 From: Jean-Paul Calderone Date: Wed, 27 Feb 2019 11:05:24 -0500 Subject: [PATCH] [wip] convert logging to eliot --- src/allmydata/watchdog/inotify.py | 149 +++++++++++++++++------------- 1 file changed, 87 insertions(+), 62 deletions(-) diff --git a/src/allmydata/watchdog/inotify.py b/src/allmydata/watchdog/inotify.py index 92020273e..da2bf18c5 100644 --- a/src/allmydata/watchdog/inotify.py +++ b/src/allmydata/watchdog/inotify.py @@ -22,18 +22,24 @@ from twisted.internet import reactor from twisted.python.filepath import FilePath from allmydata.util.fileutil import abspath_expanduser_unicode +from eliot import ( + ActionType, + MessageType, + Message, + Field, + preserve_context, + start_action, +) + from allmydata.util.pollmixin import PollMixin from allmydata.util.assertutil import _assert, precondition -from allmydata.util import log, encodingutil +from allmydata.util import encodingutil from allmydata.util.fake_inotify import humanReadableMask, \ IN_WATCH_MASK, IN_ACCESS, IN_MODIFY, IN_ATTRIB, IN_CLOSE_NOWRITE, IN_CLOSE_WRITE, \ IN_OPEN, IN_MOVED_FROM, IN_MOVED_TO, IN_CREATE, IN_DELETE, IN_DELETE_SELF, \ IN_MOVE_SELF, IN_UNMOUNT, IN_Q_OVERFLOW, IN_IGNORED, IN_ONLYDIR, IN_DONT_FOLLOW, \ IN_MASK_ADD, IN_ISDIR, IN_ONESHOT, IN_CLOSE, IN_MOVED, IN_CHANGED - - - TRUE = 0 FALSE = 1 @@ -42,10 +48,34 @@ STARTED = "STARTED" STOPPING = "STOPPING" STOPPED = "STOPPED" -class INotifyEventHandler(FileSystemEventHandler): +_PATH = Field.for_types( + u"path", + [bytes, unicode], + u"The path an inotify event concerns.", +) +MAYBE_NOTIFY = ActionType( + u"watchdog:inotify:maybe-notify", + [], + [], + u"An inotify event is being considered for dispatch to an application handler.", +) + +ANY_INOTIFY_EVENT = ActionType( + u"watchdog:inotify:any-event", + [_PATH], + [], + u"An inotify event is being dispatched.", +) + +CALLBACK = MessageType( + u"watchdog:inotify:callback", + [], + u"An inotify event is being dispatched to an application callback." +) + +class INotifyEventHandler(FileSystemEventHandler): def __init__(self, path, mask, callbacks, pending_delay): - print "init INotifyEventHandler" FileSystemEventHandler.__init__(self) self._path = path self._mask = mask @@ -53,8 +83,31 @@ class INotifyEventHandler(FileSystemEventHandler): self._pending_delay = pending_delay self._pending = set() + def _maybe_notify(self, path, event): + with MAYBE_NOTIFY(): + event_mask = IN_CHANGED + if isinstance(event, FileModifiedEvent): + event_mask = event_mask | IN_CLOSE_WRITE + event_mask = event_mask | IN_MODIFY + if isinstance(event, (DirCreatedEvent, FileCreatedEvent)): + # For our purposes, IN_CREATE is irrelevant. + event_mask = event_mask | IN_CLOSE_WRITE + if isinstance(event, (DirDeletedEvent, FileDeletedEvent)): + event_mask = event_mask | IN_DELETE + if event.is_directory: + event_mask = event_mask | IN_ISDIR + if not (self._mask & event_mask): + return + for cb in self._callbacks: + try: + with CALLBACK(): + cb(None, FilePath(path), event_mask) + except: + # Eliot already logged the exception for us. + # There's nothing else we can do about it here. + pass + def process(self, event): - print "FILESYSTEM ENCODING: %s" % encodingutil.get_filesystem_encoding() event_filepath_u = event.src_path.decode(encodingutil.get_filesystem_encoding()) event_filepath_u = abspath_expanduser_unicode(event_filepath_u, base=self._path) @@ -62,40 +115,16 @@ class INotifyEventHandler(FileSystemEventHandler): # ignore events for parent directory return - def _maybe_notify(path): - try: - if path in self._pending: - return - self._pending.add(path) - def _do_callbacks(): - self._pending.remove(path) - event_mask = IN_CHANGED - if isinstance(event, FileModifiedEvent): - event_mask = event_mask | IN_CLOSE_WRITE - event_mask = event_mask | IN_MODIFY - if isinstance(event, (DirCreatedEvent, FileCreatedEvent)): - # For our purposes, IN_CREATE is irrelevant. - event_mask = event_mask | IN_CLOSE_WRITE - if isinstance(event, (DirDeletedEvent, FileDeletedEvent)): - event_mask = event_mask | IN_DELETE - if event.is_directory: - event_mask = event_mask | IN_ISDIR - if not (self._mask & event_mask): - return - for cb in self._callbacks: - try: - cb(None, FilePath(path), event_mask) - except Exception, e: - print e - log.err(e) - _do_callbacks() - except Exception as e: - print("BAD STUFF", e) - reactor.callFromThread(_maybe_notify, event_filepath_u) + reactor.callFromThread( + preserve_context(self._maybe_notify), + event_filepath_u, + event, + ) def on_any_event(self, event): - print "PROCESS EVENT %r" % (event,) - self.process(event) + with ANY_INOTIFY_EVENT(path=self._path): + self.process(event) + class INotify(PollMixin): """ @@ -118,38 +147,34 @@ class INotify(PollMixin): self._state = NOT_STARTED def set_pending_delay(self, delay): - print "set pending delay" + Message.log(message_type=u"watchdog:inotify:set-pending-delay", delay=delay) assert self._state != STARTED self._pending_delay = delay self._observer = Observer(timeout=self._pending_delay) def startReading(self): - print "START READING BEGIN" - assert self._state != STARTED - try: - # XXX twisted.internet.inotify doesn't require watches to - # be set before startReading is called. - # _assert(len(self._callbacks) != 0, "no watch set") - self._observer.start() - self._state = STARTED - except Exception, e: - log.err(e) - self._state = STOPPED - raise - print "START READING END" + with start_action(action_type=u"watchdog:inotify:start-reading"): + assert self._state != STARTED + try: + # XXX twisted.internet.inotify doesn't require watches to + # be set before startReading is called. + # _assert(len(self._callbacks) != 0, "no watch set") + self._observer.start() + self._state = STARTED + except: + self._state = STOPPED + raise def stopReading(self): - print "stopReading begin" - if self._state != STOPPED: - self._state = STOPPING - self._observer.unschedule_all() - self._observer.stop() - self._observer.join() - self._state = STOPPED - print "stopReading end" + with start_action(action_type=u"watchdog:inotify:stop-reading"): + if self._state != STOPPED: + self._state = STOPPING + self._observer.unschedule_all() + self._observer.stop() + self._observer.join() + self._state = STOPPED def wait_until_stopped(self): - print "wait until stopped" return self.poll(lambda: self._state == STOPPED) def _isWatched(self, path_u):