June 16, 2016

Filesystem events

In 2011 I started working on a project that at its core used the Linux iNotify kernel service to distribute and record file events. These events where then processed to a subscription service allowing subscribing clients to respond to these file changes. Today, in 2016 I considered porting parts of this system for producing an API, when I stumbled upon the magnificent fswatch program written and maintained by Enrico M. Crisostomo.

The fswatch will save me plenty of work in the porting task. As fswatch the core services of inotify, FSEvents, Kqueue, ReadDirectoryW etc. The following post is an investigation of the fswatch program, with respect to the requirements for the earlier mentioned project.  Fswatch comes from a couple of installation sources, MacPorts, Brew and source, choose your favourite method to get fswatch.

$ sudo port install fswatch
Password:
Warning: port definitions are more than two weeks old, consider updating them by running 'port selfupdate'.
--->  Fetching archive for fswatch
--->  Attempting to fetch fswatch-1.9.2_0.darwin_15.x86_64.tbz2 from https://packages.macports.org/fswatch
--->  Attempting to fetch fswatch-1.9.2_0.darwin_15.x86_64.tbz2.rmd160 from https://packages.macports.org/fswatch
--->  Installing fswatch @1.9.2_0
--->  Activating fswatch @1.9.2_0
--->  Cleaning fswatch
--->  Updating database of binaries
--->  Scanning binaries for linking errors

--->  No broken files found.       

That takes care of the fswatch installation. If you're curious like me you'll need the source to check any details. The source for fswatch can be downloaded from the official github repository.

$ tar -zxvf fswatch-1.9.2.tar.gz 
x fswatch-1.9.2/
x fswatch-1.9.2/.gitignore
x fswatch-1.9.2/.idea/
<snipped>

The above extracts the source. Now we're ready for investigations. According to the fswatch readme file you start fswatch by giving the program a set of paths to monitor i.e. 

$ fswatch [options] ... path-0 ... path-n
So, lets check to see what happens when we run the program fire up a terminal and issue:

$ fswatch -1 /Users/bobo/Documents/src/bash/

The -1 opting to fswatch ensures a single event is thrown. Notice the process waits until something happens. Now fire up another terminal and create a new file in the watched directory like this:

$ touch /Users/bobo/Documents/src/newfile.sh

As soon as the new file is created fswatch exits after displaying the new files path. You can see this when you switch back to the first terminal, the terminal containing the fswatch program.

/Users/bobo/Documents/src/bash/newfile.sh

Now, lets try to leave fswatch running for a while, to see how it reports on several changes.

$ fswatch /Users/bobo/Documents/src/bash/

Try to remove the newly created file, in a different terminal than the one running fswatch issue

$ echo "stuff" > /Users/bobo/Documents/src/newfile.sh

Notice that fswatch again reports the path but doesn't stop running.

$ echo "more stuff" >> /Users/bobo/Documents/src/bash/newfile.sh

Another echo of the affected file, lets check the changes to the file:

$ cat /Users/bobo/Documents/src/bash/newfile.sh 
stuff
more stuff

Both lines are in there. Now lets's remove the file 

$ rm /Users/bobo/Documents/src/bash/newfile.sh

And again fswatch reports the filepath, but now the file is removed. Notice that the default behaviour of fswatch is to only report the path of the affected file, not what happened to the file. We'd like to know the change as this is part of the provided subscription service. Also notice that when catting the file fswatch did not report an event, this is because the file was not written only accessed. This means that fswatch cannot report file access only writes. Let's check to see if this holds.

$ fswatch -nt /Users/bobo/Documents/src/bash/

The above command starts fswatch using two options, the first (n) displays the fswatch event number, the second (t) prints a timestamp. Now from a different terminal run the above commands again.

$ touch /Users/bobo/Documents/src/bash/newfile.sh
$ echo "stuff" > /Users/bobo/Documents/src/bash/newfile.sh 
$ echo "more stuff" >> /Users/bobo/Documents/src/bash/newfile.sh 
$ rm /Users/bobo/Documents/src/bash/newfile.sh 

Then check the report from fswatch in the previous terminal:

Wed Jun 15 10:51:30 2016 /Users/bobo/Documents/src/bash/newfile.sh 514
Wed Jun 15 10:51:43 2016 /Users/bobo/Documents/src/bash/newfile.sh 517
Wed Jun 15 10:51:50 2016 /Users/bobo/Documents/src/bash/newfile.sh 517
Wed Jun 15 10:51:53 2016 /Users/bobo/Documents/src/bash/newfile.sh 525

So, as you can see fswatch reports different events when you use the -n option, and a timestamp thanks to the -t option. The events are somewhat cloudy, since the numbers 514,517 and 525 really dosen't tell much about what happened. We only know because the issued the commands from the terminal that forced these events. Lets try the -x option to see if this contain more information.

$ fswatch -xt /Users/bobo/Documents/src/bash/

If you issue fswatch -xtn the output for the -x option is suppressed due to the -n option. Again issue the commands and check the output.

Wed Jun 15 11:01:40 2016 /Users/bobo/Documents/src/bash/newfile.sh Created IsFile
Wed Jun 15 11:01:50 2016 /Users/bobo/Documents/src/bash/newfile.sh Created PlatformSpecific Updated IsFile
Wed Jun 15 11:01:53 2016 /Users/bobo/Documents/src/bash/newfile.sh Created PlatformSpecific Updated IsFile
Wed Jun 15 11:02:01 2016 /Users/bobo/Documents/src/bash/newfile.sh Created Removed PlatformSpecific Updated IsFile

Notice the:

Created IsFile
Created PlatformSpecific Updated IsFile
Created Removed PlatformSpecific Updated IsFile

All events are nicely shown in text, ready to be used with any other system. There are many more options to the fswatch program. These options can be used in many different ways. You should check the documentation for details. For me these details are sufficient for the subscription requirements needed for an update service.

There is only one issue with fswatch. I'd love if the program could be run i a deamon mode, allowing me to add and remove watches on the fly. This is the only issues that needs solving before the subscriber update relations can be ported.

Luckily,  The fswatch source includes the libfswatch, which can be used from within any c/cpp source project. The library is sufficient for including fswatch in a subscription deamon. Libfswatch is installed along side the fswatch program. If you used MacPorts the library recides in the /opt/local/lib/ folder, and it's include files are present in the /opt/local/include/libfswatch folder.

Optional you can build the libraries by hand using the source. To build and install libfswatch simply cd to the root of the fswatch source code and run the following commands: ./autogen.sh, ./configure, make, and make install.

$fswatch-1.9.2/$ ./autogen.sh 
autoreconf: Entering directory `.'
autoreconf: running: /opt/local/bin/autopoint --force
Copying file ABOUT-NLS
Creating directory config
Copying file config/config.rpath
Copying file m4/codeset.m4
Copying file m4/extern-inline.m4
Copying file m4/fcntl-o.m4
Copying file m4/gettext.m4
Copying file m4/glibc2.m4
<snipped>
configure.ac:44: installing 'config/install-sh'
configure.ac:44: installing 'config/missing'
doc/Makefile.am:16: installing 'config/mdate-sh'
doc/Makefile.am:16: installing 'config/texinfo.tex'
src/Makefile.am: installing 'config/depcomp'
autoreconf: Leaving directory `.'

Now, we're interested in building only the libfswatch therefore we need to change to this directory and run configure from there

fswatch-1.9.2/$ cd libfswatch/
fswatch-1.9.2/libfswatch/$ ./configure
checking build system type... x86_64-apple-darwin15.5.0
checking host system type... x86_64-apple-darwin15.5.0
checking target system type... x86_64-apple-darwin15.5.0
checking for a BSD-compatible install... /opt/local/bin/ginstall -c
checking whether build environment is sane... yes
checking for a thread-safe mkdir -p... /opt/local/bin/gmkdir -p
<snipped>
config.status: executing po-directories commands
config.status: creating po/POTFILES
config.status: creating po/Makefile

When configure is done, run make

fswatch-1.9.2/libfswatch/$ make
/Applications/Xcode.app/Contents/Developer/usr/bin/make  all-recursive
Making all in src
Making all in libfswatch
  CXX      c/cevent.lo
  CXX      c/libfswatch.lo
  CXX      c/libfswatch_log.lo
  CXX      c++/libfswatch_exception.lo
  CXX      c++/event.lo
<snipped>
make[3]: Nothing to be done for `all-am'.
make[2]: Nothing to be done for `all-am'.

The the lib is installed issuing make install

fswatch-1.9.2/libfswatch/$ make install
Making install in src
Making install in libfswatch
 /opt/local/bin/gmkdir -p '/usr/local/lib'
<snipped>
/opt/local/bin/gmkdir -p '/usr/local/share/doc/libfswatch'
 /opt/local/bin/ginstall -c -m 644 README.md AUTHORS COPYING LICENSE NEWS '/usr/local/share/doc/libfswatch'

Lets check to see if we can find the installed libfswatch

$ ls -l /usr/local/lib/libfswatch.*
-rwxr-xr-x  1 bobo  wheel   184044 15 Jun 11:45 /usr/local/lib/libfswatch.6.dylib
-rw-r--r--  1 bobo  wheel  4431560 15 Jun 11:45 /usr/local/lib/libfswatch.a
lrwxr-xr-x  1 bobo  wheel       18 15 Jun 11:45 /usr/local/lib/libfswatch.dylib -> libfswatch.6.dylib
-rwxr-xr-x  1 bobo  wheel      965 15 Jun 11:45 /usr/local/lib/libfswatch.la

It's present in the /usr/local/lib/ directory on my machine, hopefully its also there on yours. Next check the libfswatch API headers

$ ls -lR /usr/local/include/libfswatch/
total 0
drwxr-xr-x   9 bobo  admin  306 15 Jun 11:45 c
drwxr-xr-x  13 bobo  admin  442 15 Jun 11:45 c++

/usr/local/include/libfswatch//c:
total 72
-rw-r--r--  1 bobo  admin  5688 15 Jun 11:45 cevent.h
-rw-r--r--  1 bobo  admin  1522 15 Jun 11:45 cfilter.h
-rw-r--r--  1 bobo  admin  1847 15 Jun 11:45 cmonitor.h
-rw-r--r--  1 bobo  admin  2684 15 Jun 11:45 error.h
-rw-r--r--  1 bobo  admin  6991 15 Jun 11:45 libfswatch.h
-rw-r--r--  1 bobo  admin  2900 15 Jun 11:45 libfswatch_log.h
-rw-r--r--  1 bobo  admin  1456 15 Jun 11:45 libfswatch_types.h

/usr/local/include/libfswatch//c++:
total 136
-rw-r--r--  1 bobo  admin   3312 15 Jun 11:45 event.hpp
-rw-r--r--  1 bobo  admin   2776 15 Jun 11:45 filter.hpp
-rw-r--r--  1 bobo  admin   2559 15 Jun 11:45 fsevents_monitor.hpp
-rw-r--r--  1 bobo  admin   2854 15 Jun 11:45 kqueue_monitor.hpp
-rw-r--r--  1 bobo  admin   2132 15 Jun 11:45 libfswatch_exception.hpp
-rw-r--r--  1 bobo  admin   1838 15 Jun 11:45 libfswatch_map.hpp
-rw-r--r--  1 bobo  admin   1767 15 Jun 11:45 libfswatch_set.hpp
-rw-r--r--  1 bobo  admin  27727 15 Jun 11:45 monitor.hpp
-rw-r--r--  1 bobo  admin   2625 15 Jun 11:45 path_utils.hpp
-rw-r--r--  1 bobo  admin   2807 15 Jun 11:45 poll_monitor.hpp
-rw-r--r--  1 bobo  admin   1693 15 Jun 11:45 string_utils.hpp

All there and ready to run. There may be an issue with g++ and the use of the libraries as there is no *.pc file that explains the system where the libraries are. If you just installed fswatch, you can use the installed library directly.

The source for the simple fswatch_test program has been taken from the readme file of fswatch, I only added some error checking etc.

$ cat fswatch_test.c
#include <stdio.h>
#include <stdlib.h>
#include <libfswatch/c/libfswatch.h>

/**
 * The following function implements the callback functionality
 * for testing eventnumber send from the
 * libfswatch library. See FSW_CEVENT_CALLBACK for details.
 */
void my_callback(fsw_cevent const * const events, const unsigned int event_num, void * data) {
  printf("my_callback: %d\n",event_num);
}

int main(int argc, char **argv) {

  if(2 <= argc) {
    if(FSW_OK == fsw_init_library()) {

      const FSW_HANDLE handle = fsw_init_session();
      if(FSW_INVALID_HANDLE != handle) {

/* Loop and add all paths passed to the fsw session */
int j = 0;
for(j=1;j<argc;j++) {
 if(FSW_OK != fsw_add_path(handle,argv[j])) {
   fsw_last_error();
 }
}

if(FSW_OK != fsw_set_callback(handle, my_callback,NULL)) {
 fsw_last_error();
}

if(FSW_OK != fsw_start_monitor(handle)) {
 fsw_last_error();  
}
      }
      else {
fsw_last_error();
(void)printf("Invalid fswatch handle: %d\n",handle);
      }
    }
    else {
      fsw_last_error();  
      (void)printf("fswatch cannot be initialised!\n");
    }
  }
  else {
    (void)printf("usage: %s [path]\n",argv[0]);
  }
  return 0;

}

The above program can be used like the fswatch program. As the test program simply adds all passed paths using the libfswatch calls. Then the program registers a callback for echoing the fs events to the terminal. Finally, the test program starts the fsw monitor. All this is done using the libfswatch c style functions. If something goes wrong the test program checks the error and writes this to the terminal. Compile and run using:

$ g++ -I /opt/local/include -o "fswatch_test" fswatch_test.c /opt/local/lib/libfswatch.a 

Or you can add the LDFLAGS environment variable to your path or to a seperate file and then source this file when building. This issue is explained in details here. Now, run the program


$ ./fswatch_test /Users/bobo/Documents/src/bash/

Segmentation fault: 11

Yikes, segfault. Seems like we have some debugging on the road ahead. But before I dwell into gdb to check whats wrong, I usually run the program using valgrind, usually this neat little program will tell me where things went wrong.

$ valgrind ./fswatch_test "/Users/bobo/Documents/src/bash/"
==1021== Memcheck, a memory error detector
==1021== Copyright (C) 2002-2015, and GNU GPL'd, by Julian Seward et al.
==1021== Using Valgrind-3.11.0 and LibVEX; rerun with -h for copyright info
==1021== Command: ./fswatch_test /Users/bobo/Documents/src/bash/
==1021== 
--1021-- run: /usr/bin/dsymutil "./fswatch_test"
warning: no debug symbols in executable (-arch x86_64)
==1021== Invalid write of size 1
==1021==    at 0x100005BB2: fsw::monitor::set_allow_overflow(bool) (in ./fswatch_test)
==1021==    by 0x100001DE8: fsw_start_monitor (in ./fswatch_test)
==1021==    by 0x10000129A: main (in ./fswatch_test)
==1021==  Address 0x51 is not stack'd, malloc'd or (recently) free'd
==1021== 
==1021== 
==1021== Process terminating with default action of signal 11 (SIGSEGV)
==1021==  Access not within mapped region at address 0x51
==1021==    at 0x100005BB2: fsw::monitor::set_allow_overflow(bool) (in ./fswatch_test)
==1021==    by 0x100001DE8: fsw_start_monitor (in ./fswatch_test)
==1021==    by 0x10000129A: main (in ./fswatch_test)
==1021==  If you believe this happened as a result of a stack
==1021==  overflow in your program's main thread (unlikely but
==1021==  possible), you can try to increase the size of the
==1021==  main thread stack using the --main-stacksize= flag.
==1021==  The main thread stack size used in this run was 8388608.
==1021== 
==1021== HEAP SUMMARY:
==1021==     in use at exit: 22,441 bytes in 196 blocks
==1021==   total heap usage: 268 allocs, 72 frees, 28,585 bytes allocated
==1021== 
==1021== LEAK SUMMARY:
==1021==    definitely lost: 40 bytes in 2 blocks
==1021==    indirectly lost: 0 bytes in 0 blocks
==1021==      possibly lost: 0 bytes in 0 blocks
==1021==    still reachable: 392 bytes in 8 blocks
==1021==         suppressed: 22,009 bytes in 186 blocks
==1021== Rerun with --leak-check=full to see details of leaked memory
==1021== 
==1021== For counts of detected and suppressed errors, rerun with: -v
==1021== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 0 from 0)
Segmentation fault: 11

Luckily, segfault again ;) Now valgrinds output points to the error causing the segfault. Examining the valgrind output we can see the callstack, equivalent to gdb backtrace functionality, points to the function: fsw::monitor::set_allow_overflow(bool). This function is part of the fswatch library, luckily we have the source. The error also states that the address 0x51 is not stack, or allocated. Infact an address of 0x51 seems to be uninitialized memory.

$ grep -n "fsw_start_monitor" ../fswatch-1.9.2/libfswatch/src/libfswatch/c/*.cpp
../fswatch-1.9.2/libfswatch/src/libfswatch/c/libfswatch.cpp:212: * next time a monitor is started with fsw_start_monitor().
../fswatch-1.9.2/libfswatch/src/libfswatch/c/libfswatch.cpp:273: *     fsw_start_monitor(handle);
../fswatch-1.9.2/libfswatch/src/libfswatch/c/libfswatch.cpp:840:FSW_STATUS fsw_start_monitor(const FSW_HANDLE handle)

Finds a few things, like the definition of the fsw_start_monitor function on line 840. Lets sed it

$ sed -n '840,880'p ../fswatch-1.9.2/libfswatch/src/libfswatch/c/libfswatch.cpp 
FSW_STATUS fsw_start_monitor(const FSW_HANDLE handle)
{
  try
  {
#ifdef HAVE_CXX_MUTEX
    unique_lock<mutex> session_lock(session_mutex, defer_lock);
    session_lock.lock();
#endif

    FSW_SESSION *session = get_session(handle);

#ifdef HAVE_CXX_MUTEX
# ifdef HAVE_CXX_ATOMIC
    if (session->running.load(memory_order_acquire))
      return fsw_set_last_error(int(FSW_ERR_MONITOR_ALREADY_RUNNING));
# endif

#  ifdef HAVE_CXX_UNIQUE_PTR
    unique_ptr<mutex>& sm = session_mutexes.at(handle);
    lock_guard<mutex> lock_sm(*sm.get());
#  else
    mutex * sm = session_mutexes.at(handle);
    lock_guard<mutex> lock_sm(*sm);
#  endif

    session_lock.unlock();
#endif

    if (!session->monitor)
      create_monitor(handle, session->type);

    session->monitor->set_allow_overflow(session->allow_overflow);
    session->monitor->set_filters(session->filters);
    session->monitor->set_event_type_filters(session->event_type_filters);
    session->monitor->set_follow_symlinks(session->follow_symlinks);
    if (session->latency) session->monitor->set_latency(session->latency);
    session->monitor->set_recursive(session->recursive);
    session->monitor->set_directory_only(session->directory_only);

#ifdef HAVE_CXX_MUTEX
# ifdef HAVE_CXX_ATOMIC

The bold line seems to be the call in question, according to valgrinds output. Lets have a look in the monitor implementation file.

$ sed -n '73,83'p ../fswatch-1.9.2/libfswatch/src/libfswatch/c++/monitor.cpp
  void monitor::set_allow_overflow(bool overflow)
  {
    allow_overflow = overflow;
  }

This small function seems to set a member in the monitor object. So, by reading the valgrind error again I'd think that the problem is that the session or monitor object has not been correctly allocated or stacked. So the issue must be that either the c interface I used in my test program does not ensure that the session or monitor is not created correctly, or the session or monitor class has some kind of initialisation error. That's as far as the evaluation goes for now. Stranded on an initialisation issue.

No comments: