OS X kqueue based WatchService

[Michael Hall]

On Jun 20, 2013, at 6:49 AM, Alan Bateman wrote:

> On 19/06/2013 23:39, Michael Hall wrote:
>> 
>> I had done some OS X nio.2 coding for my trz package, see below.
>> This had included a kqueue implementation of a WatchService to possibly use instead of the built-in polling one.
> Good to hear this, it's been on the list for a while to add a kqueue based WatchService implementation (the original Mac port missed it so this is why we uses the fallback polling implementation).

Alan,

Thanks for the response. 
This will have to be a little less brief to answer your question as to whats being done.

The concerned part of the LotsOfEvents test looks like this….

        WatchKey key = watcher.poll(15, TimeUnit.SECONDS);
        if (key != null && count == 0)
            throw new RuntimeException("Key was signalled (unexpected)");
        if (key == null && count > 0)
            throw new RuntimeException("Key not signalled (unexpected)");
        int nread = 0;
        boolean gotOverflow = false;
        // mjh - test
        Date date = new Date();
        SimpleDateFormat sdf = new SimpleDateFormat("MM/dd/yyyy h:mm:ss a");
        // end of test
        while (key != null) {
            List<WatchEvent<?>> events = key.pollEvents();
            for (WatchEvent<?> event: events) {
                WatchEvent.Kind<?> kind = event.kind();
                if (kind == expectedKind) {
                    // expected event kind
                    if (++nread > count)
                        throw new RuntimeException("More events than expected!!");
                } else if (kind == OVERFLOW) {
                    // overflow event should not be retrieved with other events
                    if (events.size() > 1)
                        throw new RuntimeException("Overflow retrieved with other events");
                    gotOverflow = true;
                } else {
                    throw new RuntimeException("Unexpected event '" + kind + "'");
                }
            }
            if (!key.reset())
                throw new RuntimeException("Key is no longer valid");
            System.out.println(sdf.format(date) + " LotsOfEvents before repoll num read " + nread);
            key = watcher.poll(2, TimeUnit.SECONDS);
            date = new Date();
            System.out.println(sdf.format(date) + " LotOfEvents after repoll key is " + key);
        }

Some of my debug messages in there to see timings. This shows the poll, drain, and re-poll.

The kqueue native as stated runs on it's own thread…

	// Start new thread that fetches and processes our events:
	keepThreadRunning = YES;
	[NSThread detachNewThreadSelector:@selector(watcherThread:) toTarget:self withObject:nil];

The debug messages for the part concerned….
postNativeEvent: foo1001 1 Thread[Thread-0,5,main]
2013-06-19 17:00:04.609 java[1413:5003] going into kevent
06/19/2013 5:00:05 PM AWS poll in
06/19/2013 5:00:05 PM AWS poll pending keys
06/19/2013 5:00:05 PM AWS poll check key
06/19/2013 5:00:05 PM AWS poll out
poll returning KQueueWatchKey: /var/folders/nh/2yzwp0g119d794lrrfwkn9ym0000gp/T/name6592800248940171085 events: [ENTRY_DELETE, ENTRY_CREATE] post events 0 false
06/19/2013 5:00:05 PM LotsOfEvents before repoll num read 25
06/19/2013 5:00:05 PM AWS poll in
06/19/2013 5:00:05 PM AWS poll pending keys
06/19/2013 5:00:07 PM AWS poll check key
06/19/2013 5:00:07 PM AWS poll out
poll returning null post events 0 false
06/19/2013 5:00:07 PM LotOfEvents after repoll key is null
java.lang.RuntimeException: Insufficient events read 25 count 1024
	at LotsOfEvents.drainAndCheckOverflowEvents(LotsOfEvents.java:179)
	at LotsOfEvents.testOverflowEvent(LotsOfEvents.java:118)
	at LotsOfEvents.main(LotsOfEvents.java:49)
2013-06-19 17:00:08.066 java[1413:5003] n 1 keepThreadRunning: YES
2013-06-19 17:00:08.071 java[1413:5003] postJava 26
postNativeEvent: foo0 8 Thread[Thread-0,5,main]
AWS enqueueKey KQueueWatchKey: /var/folders/nh/2yzwp0g119d794lrrfwkn9ym0000gp/T/name6592800248940171085 events: [ENTRY_DELETE, ENTRY_CREATE]
2013-06-19 17:00:08.079 java[1413:5003] going into kevent
2013-06-19 17:00:08.082 java[1413:5003] n 1 keepThreadRunning: YES
2013-06-19 17:00:08.116 java[1413:5003] postJava 27

postNativeEvent is the kqueue -> java callback to post events. AWS indicates that it is code in my slightly modified AbstractWatchService. You see the initial poll process that immediately ends after finding something. After processing that it tries to repoll to get more. Nothing happens and it errors for not having handled all the 4096 file creates it did for this part of the test.

Going into this the native showed this... 
2013-06-19 17:00:04.609 java[1413:5003] going into kevent
Which should mean it's sitting on the kevent waiting for events.
After the RuntimeException it picks up again almost immediately showing it's out of this wait with…
2013-06-19 17:00:08.066 java[1413:5003] n 1 keepThreadRunning: YES

to show that it's processing one event from the kevent invocation. 
It continues from there to keep pumping events until java completes processing of the RuntimeException and shuts the test down. 
Only during the code shown above does it appear to be somehow blocked, doing nothing. For about 3 seconds. Which ensures the test will fail once it drains and gets no more work. 
Why would it be idle during this part of the test? Is there something about how java is blocking that also blocks it or what?

Michael Hall

trz nio.2 for OS X http://www195.pair.com/mik3hall/index.html#trz

HalfPipe Java 6/7 shell app http://www195.pair.com/mik3hall/index.html#halfpipe

AppConverter convert Apple jvm to openjdk apps http://www195.pair.com/mik3hall/index.html#appconverter



-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://mail.openjdk.java.net/pipermail/nio-dev/attachments/20130620/1c58d558/attachment.html