python

Timing Issues with pyinotify


Ok so lets look a that little issue with pyinotify, and it really is only little, but enough to keep you on your toes. So this is the issue in brief.

START LOOP 2009-05-11 21:55:39.733393
Result of notifier.check_events() = TRUE
Calling notifier.process_events()
<Event dir=False mask=0x20 maskname=IN_OPEN name=foo path=/tmp pathname=/tmp/foo wd=1 >
END LOOP 2009-05-11 21:55:40.339782
START LOOP 2009-05-11 21:55:40.339807
Result of notifier.check_events() = TRUE
Calling notifier.process_events()
<Event dir=False mask=0x4 maskname=IN_ATTRIB name=foo path=/tmp pathname=/tmp/foo wd=1 >
END LOOP 2009-05-11 21:55:40.340403
START LOOP 2009-05-11 21:55:40.340426
Result of notifier.check_events() = TRUE
Calling notifier.process_events()
<Event dir=False mask=0x8 maskname=IN_CLOSE_WRITE name=foo path=/tmp pathname=/tmp/foo wd=1 >
END LOOP 2009-05-11 21:55:40.340971


So here is the culprit notifier = pyinotify.Notifier(m, e(), 0, 0, 1000) (I’ve altered the timeout to accentuate the issue). Take a careful look at the timings between the event output lines and you can see that they are uneven. This is because the timeout isn’t a spacer, its just a wait and the events are not linearly spaced.


My error was my own of course. The lesson here is read the code through twice and check it more for design flaws.


Simple Custom Event Processor for pyinotify

In my previous post on pyinotify I took a short look at the basic use of the pyinotify watcher using mostly default settings. Here I take a brief look at building a custom event processor. The event processor is called to retrieve the event data and, well, process it. The default processor simply prints the output to ‘stdout‘; mine will too. But it is just there to show how simple it is. Note that the processor actually processes the events in line so there’s no need for messy threading.


#!/usr/bin/python

import os
import pyinotify
from datetime import datetime

m = pyinotify.WatchManager()
notifier = pyinotify.Notifier(m, pyinotify.ProcessEvent(), 0,  0, 100)
m.add_watch('/tmp', pyinotify.ALL_EVENTS, rec=True)

while True:

    print "START LOOP %s " % datetime.now()

    try:
        if notifier.check_events():
            print "Result of notifier.check_events() = TRUE"
            notifier.read_events()
            print "Calling notifier.process_events()"
            notifier.process_events()

    except KeyboardInterrupt:
        notifier.stop()
        break

    print "END LOOP %s " % datetime.now()


This is just the same code as we saw in the earlier post except that I’ve put the ‘notifier.process_events()‘ in its proper place so that it doesn’t get called in every loop execution. It is restricted by the ‘notifier.check_events()‘. To add a little info to the whole process I’ve included some print statements to illustrate the flow of execution. With this we get results that look like:


START LOOP 2009-05-07 23:02:25.025048
Result of notifier.check_events() = TRUE
Calling notifier.process_events()



END LOOP 2009-05-07 23:02:25.104546


Which is what you’d expect. However you will also get results that look like.


START LOOP 2009-05-07 23:02:18.808039
Result of notifier.check_events() = TRUE
Calling notifier.process_events()

END LOOP 2009-05-07 23:02:18.863855
START LOOP 2009-05-07 23:02:18.863912
Result of notifier.check_events() = TRUE
Calling notifier.process_events()

END LOOP 2009-05-07 23:02:18.864656
START LOOP 2009-05-07 23:02:18.864710
Result of notifier.check_events() = TRUE
Calling notifier.process_events()

END LOOP 2009-05-07 23:02:18.865415


So you can see that we get some reasonably unpredictable results.

Now let’s do something a little different and collect the event and print it ourselves a little differently. In this case we’re still collecting all events, we just wanted to mark up the output with something extra.


#!/usr/bin/python

import os
import pyinotify
from datetime import datetime

class e(pyinotify.ProcessEvent):
    def process_default(self, event):
        print(repr(event))

m = pyinotify.WatchManager()
notifier = pyinotify.Notifier(m, e(), 0,  0, 100)
m.add_watch('/tmp', pyinotify.ALL_EVENTS, rec=True)

while True:

    print "START LOOP %s " % datetime.now()

    try:
        if notifier.check_events():
            print "Result of notifier.check_events() = TRUE"
            notifier.read_events()
            print "Calling notifier.process_events()"
            notifier.process_events()

    except KeyboardInterrupt:
        notifier.stop()
        break

    print "END LOOP %s " % datetime.now()


Easy huh? But there’s still a little more, there’s a problem! More on that later.


Python and pyinotify

A friend of mine posted a really good article over at blogspot about using pyinotify; after reading one of the comments there I started playing around with it. So if you want the original have a look at David Latham’s original post. I’ve simplified the code just a little to get to the essence of pyinotify. Incidentally if you’re working from Fedora like I am you might like to ‘yum install python-inotify*‘ and confirm that the module and documentation are installed. Here’s the base version.


#!/usr/bin/python

import os
import pyinotify

m = pyinotify.WatchManager()
notifier = pyinotify.Notifier(m, pyinotify.ProcessEvent())
m.add_watch('/tmp/', pyinotify.ALL_EVENTS, rec=True)

while True:

    try:
        notifier.process_events()
        if notifier.check_events():
            notifier.read_events()

    except KeyboardInterrupt:
        notifier.stop()
        break


It works really well for this example but has one generally unwelcome side effect. It also blocks on the ‘notifier.check_events()‘ call. A blocking call is not really what you want in an event loop so it doesn’t really work too well for the core of the application. However this is overcome very simply by adding the three extra parameters defining the wait timing of the ‘pyinotify.Notifier(m, pyinotify.ProcessEvent(), 0, 0, 10)‘. In this case the block is turned to a 10 second wait courtesy of the last parameter as shown in the next code snippet below. In an application event loop you would use a value of 0 meaning that the call would not block at all.


#!/usr/bin/python

import os
import pyinotify

m = pyinotify.WatchManager()
notifier = pyinotify.Notifier(m, pyinotify.ProcessEvent(), 0, 0, 10)
m.add_watch('/tmp/', pyinotify.ALL_EVENTS, rec=True)

while True:

    try:
        notifier.process_events()
        if notifier.check_events():
            notifier.read_events()

    except KeyboardInterrupt:
        notifier.stop()
        break


In this case the default event handler just prints XML formatted event lines to stdout. But there’s just one more unexpected side effect. You may find there are a few timing issues and how do you get the notification back to the main thread? But more on that later.


Copyright © 1996-2010 Code Snips. All rights reserved.
iDream theme by Templates Next | Powered by WordPress