Rethink how we sleep in StageTask poll()

[ZNikke]

In order to allow for dsmc to finish setting attributes etc there is a sleep() in the StageTask poll():

dcache-endit-provider/src/main/java/org/ndgf/endit/StageTask.java

Line 121 in 71cf6b2

Thread.sleep(GRACE_PERIOD);

I suspect that this sleep() might be the reason for the somewhat unexpected behavior that the WatchingProvider is so slow, and the observation that the PollingProvider performs much better provided that we allocate a LOT of threads to it.

My reasoning is that although it's a Thread.sleep() it still suspends execution of the thread. This will wreak havoc with the watching provider performance and also increases the likelihood for event overflows. For the polling provider the GRACE_PERIOD of 1000 ms is a direct correlation to the observed performance of the 1-thread-per-Hz of staging performance.

What we really ought to do is something along the lines of:

• When we see a file with a correct size, add it to a FIFO queue together with the current time.
  • Thus allowing the thread to continue processing.
• Process the queue whenever we have a file at output that's been sitting there for more than GRACE_PERIOD
  • This can probably be done in lots of ways, the naive approach of checking the queue every 100ms will probably be good enough although there is likely a more elegant Java-ish way to do it. Since this ties in to the magic mess of Futures I'm at a loss what the best method may be.

I believe this would allow threads to do actual work instead of sleeping all the time.

[yhshin]

I'd like to share my experience here.

Note that I had adapted it to fit TRIUMF tape bakend's workflow in 2015 so there is slight difference but overall the fundamental logic is still same.

In 2019 TRIUMF had similar issue of slow moving of staged file from /in/ dir to pool dir. I looked at all the possible causes and found the followings;

1. too much MODIFY events during file is read from tape

2. sequential nature of watch event handling

   while (!Thread.currentThread().isInterrupted()) {
     ...
     if (event.kind().equals(StandardWatchEventKinds.OVERFLOW)) {
        pollAll();
     } else {
        poll(dir.resolve(fileName));
     }
     ...
   }

3. elapsed time for sleep(GRACE_PERIOD) and set(result)

4. OVERFLOW event

It seemed to me that the difference between file reading speed and ENDIT's polling speed was the main culprit of frequent OVERFLOW, which in turn cause a new OVERFLOW event, repeating until the system getting relatively quiet.

I don't know much about dCache internal and Java threads, but the debug messages that I put to the code showed that, for some large files, set(result) took a few seconds to return, and it looked like dCache was doing checksum verification.

Since watcher's serial nature, the events will be handled one-by-one regardless of number of threads for the tasks. While watcher was doing poll 1-at-a-time slowly, tape backend is reading files faster. This rate difference seems like a typical bucket with a hole at the bottom problem; tape pours events to the bucket and ENDIT removes them.

As a result, the buffer OVERFLOWs soon, and pollAll() runs which also run poll for each remaining requests in nondeterministic order (as returned by the Map). Thus the completed staged files were moved to pool dir not in completed order.

While looping for all the requests, more files were read and the buffer gets OVERFLOW soon again.

For MODIFY event, I tried to replace it with ON_CLOSE event but couldn't find. If I remember correctly, I found one written by Paul for dCache but wasn't able to adapt it to ENDIT.

As I mentioned, I have very limited knowledge on dCache and JAVA threads so my diagnosis may be incorrect. But I thought it may be worth to share my experience.

[yhshin]

I've also been thinking of using ZooKeeper's watch service to replace Java's WatchServe but haven't started it yet. I'm not sure whether it is worth to try or even feasible but I guess it would be able to fully exploit threads power maybe?