WatcherService hangs server at shutdown

[tompilompi]

So im running JBoss AS 7.1.1.Final "brontes" in a maven3 project running eclipse kepler and java7.

I am trying to build a watcherService that is monitoring a folder for updates. I have a Singleton that at startup initializes and then runs an asynhronous metod in another statelessbean. So far everything works and the watcherservice is started and monitors the assigned directory fine.

The problem comes to when i try to shutdown the server it hangs and won't go down and after a while eclipse tells me that the server has stopped responding.

why is this? Serverlogs doesn't say anything it just wont shutdown, i have to force quit it everytime.

here is my startup singleton

@Startup
@Singleton
@DependsOn("ExcelPropertiesLoader")
public class FileSystemMonitorInitializer {
   
    @EJB
    private ExcelPropertiesLoader excelPropertiesLoader;
   
    @EJB
    private FileSystemMonitor fileSystemMonitor;
   
    public static Logger log = Logger.getLogger(FileSystemMonitorInitializer.class.getName());;
   
    @PostConstruct
    public void init(){
       
        fileSystemMonitor.newFolderWatcher();
        fileSystemMonitor.setMonitoredDir(excelPropertiesLoader.getMonitoredDir());
        fileSystemMonitor.startWatching();
       
    }
}

and here is the actual filemonitor/watcher service:

@Stateless
public class FileSystemMonitor {

    public static Logger log = Logger.getLogger(FileSystemMonitor.class.getName());
    private WatchService watcher;
    private WatchKey key;
    private Path dir;

    public void newFolderWatcher() {
        try {
            watcher = FileSystems.getDefault().newWatchService();
        } catch (IOException e) {
            log.error("Failed to init watcher");
            e.printStackTrace();
        }
    }

    public void setMonitoredDir(String filePath) {

        dir = Paths.get(filePath);

        WatchEvent.Kind<?>[] events = { StandardWatchEventKinds.ENTRY_CREATE };
        try {
            key = dir.register(watcher, events);
        } catch (IOException e) {
            log.error("Failed to register watcher to selected directory");
            e.printStackTrace();
        }
    }

    @Asynchronous
    public void startWatching() {

        while (true) {

            log.info("Waiting for watch event");
            log.info("Path being watched: " + key.watchable());

            try {
                key = watcher.take();
            } catch (InterruptedException e) {
                log.error("Watcher got interrupted");
                e.printStackTrace();
            }

            if (key.isValid()) {
                for (WatchEvent<?> event : key.pollEvents()) {

                    if (event.kind().equals(StandardWatchEventKinds.ENTRY_CREATE) && event.count() == 1) {
                        log.info("Context: " + event.context().toString());
                        String extension = Helpers.getFileExtension(event.context().toString());
                        String fileName = key.watchable().toString() + "\\" + event.context().toString();

                        if (extension.equals("xls")) {
                            log.info("Filename: " + fileName);
                        } else if (extension.equals("xlsx")) {
                            log.info("Filename: " + fileName);
                        } else {
                            log.info("Unknown file format no action will be taken");
                        }
                    }
                    boolean result = key.reset();
                    System.out.println(result);
                }
            }
        }
    }
}

server log output at shutdown (i have enabled trace logging for arjuna and jboss.jpa

10:36:40,351 INFO  [org.jboss.as.osgi] (MSC service thread 1-11) JBAS011942: Stopping OSGi Framework
10:36:40,360 INFO  [org.jboss.as.logging] JBAS011503: Restored bootstrap log handlers
10:36:40,367 INFO  [org.jboss.as.connector.subsystems.datasources] JBAS010409: Unbound data source [java:jboss/datasources/ExampleDS]
10:36:40,372 INFO  [org.apache.catalina.core.StandardContext] Container org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/] has not been started
10:36:40,374 INFO  [org.apache.coyote.http11.Http11Protocol] Pausing Coyote HTTP/1.1 on http-localhost-127.0.0.1-8080
10:36:40,375 INFO  [org.apache.coyote.http11.Http11Protocol] Stopping Coyote HTTP/1.1 on http-localhost-127.0.0.1-8080
10:36:40,379 INFO  [org.jboss.weld.deployer] JBAS016009: Stopping weld service for deployment statistic-ear.ear
10:36:40,384 INFO  [org.jboss.as.jpa] JBAS011403: Stopping Persistence Unit Service 'statistic-ear.ear/statistic-ejb.jar#statistic'
10:36:40,388 INFO  [org.jboss.as.server.deployment] JBAS015877: Stopped deployment statistic-web.war in 29ms
10:36:40,389 INFO  [org.jboss.as.server.deployment] JBAS015877: Stopped deployment statistic-ejb.jar in 30ms
10:36:40,390 INFO  [com.arjuna.ats.jbossatx] ARJUNA032018: Destroying TransactionManagerService
10:36:40,391 INFO  [com.arjuna.ats.jbossatx] ARJUNA032014: Stopping transaction recovery manager
10:36:40,404 INFO  [org.jboss.as.server.deployment] JBAS015877: Stopped deployment statistic-ear.ear in 50ms

after that server just "waits"... i have no idea what to do.

if i dont start the async method server shutsdown fine. is it that the server is waiting for the thred to finish? i have tried predestroy to interrupt the thread, does not work....

[wdfink]

From what I see (and understand) the startWatching() method will run a endless while loop which does not stop for shutdown.

This prevent the server from stopping, all other services are down.

You might do a hack and use the Singleton @PreDestroy to send a stop.

Another possibility is to use a scheduled timer to only check the watcher once every X seconds

[tompilompi]

i thought this was the case so i did a predestroy that tries to stop the loop with no luck. @Predestroy gets called after all threads has been stop.

if i dont start the watcher. Predestroy gets run in singleton. If i run the watcher, the predestroy never gets called, cause i think the container is waiting for all threads to stop before it runs it.

I have no idea how to solves this, any suggestions?

[tompilompi]

didn't find any answers online but i managed to finally solves this so sharing my solution to whomever needs it. its not pretty but it works:

First i registered a shutdown hook with the jboss container:

Runtime.getRuntime().addShutdownHook(new Thread("shutdown watcher") {
public void run() {
    public void run(){
          try {
              watcher.close();
          } catch (IOException e) {
              e.printStackTrace();
          }
    }
}

where i attempt to close down the watcher so it stops monitoring the filesystem.

this will make the while-loop loop over the watcher and throw a "ClosedWatchServiceException". So i catched this and did a break in the loop so it breaks out of the while loop. Thread will stop and container cleans the object and does shutdown.

so full code is:

@Asynchronous
    public void startWatching() {

        WatchKey key = null;
        String fileName = null;

        Runtime.getRuntime().addShutdownHook(new Thread("shutdown watcher") {

            public void run() {
                try {
                    watcher.close();
                } catch (IOException e) {
                    e.printStackTrace();
                }
            }
        });

        while (true) {

            log.info("Waiting for watch event");
            log.info("Path being watched: " + dir.toString());

            try {
                key = watcher.take();
            } catch (InterruptedException e) {
                log.error("Watcher got interrupted");
                e.printStackTrace();
            } catch (ClosedWatchServiceException c) {
                log.info("Watchservice is closed exiting thread.");
                break;
            }

            if (key != null) {

                for (WatchEvent<?> event : key.pollEvents()) {
                    WatchEvent.Kind<?> kind = event.kind();

                    if (kind == StandardWatchEventKinds.OVERFLOW) {
                        continue;
                    }

                    String extension = Helpers.getFileExtension(event.context().toString());
                    fileName = key.watchable().toString() + "\\" + event.context().toString();

                    if (extension.equals(ReaderTypes.EXCEL97)) {

                        log.info("File found: " + fileName);
                        fileSystemMonitorInitializer.placeFactoryOrder(fileName, ReaderTypes.EXCEL97);

                    } else if (extension.equals(EXCEL_2007_FILE_EXTENSION)) {

                        log.info("File found: " + fileName);
                        fileSystemMonitorInitializer.placeFactoryOrder(fileName, ReaderTypes.EXCEL2007);

                    } else {
                        log.info("Unknown file format no action will be taken");
                    }

                    boolean valid = key.reset();
                    if (!valid) {
                        log.error("Watcher key could not be reset stopping watchservice.");
                        break;
                    }
                }
            }
        }
    }

no the pretties code i have written but it works

[wdfink]

new Thread is against the Java EE spec, but if it works for your environment there should be no big problem.

But consider that you might run into issues if you upgrade or migrate.

[wdfink]

The problem is that the Singleton has a dependency to your never ending asynchronous EJB, so the Singleton will wait forever also as the dependency does not shutdown

[radekj_]

Above solution is not working for me. Server is hanging... Any other ideas?

[d92gunka]

I solved the shutdown problem by creating a separate shutdown EJB.

@DependsOn(value = "WatcherEJB")

public class WatcherStopperEJB
{
  @PreDestroy
  public void stopWatcher() throws IOException, NamingException
  {
    watcherEjb.stopWatch();
  }
}

And instead of creating the shutdown hook, I added a method in the Watcher. The Watcher also need @Lock(LockType.READ) since startWatching and stopWatch will be executed at the same time.

@Lock(LockType.READ)
public class WatcherEJB
{
  public void stopWatch() throws IOException
  {
    watchService.close();
  }  


  @Asynchronous
  public void startWatching(){
 ...

This way creating a new thread is avoided.

[radekj_]

Tried your approach and I'm getting compiler error:

Cannot make a static reference to the non-static method stopWatch() from the type WatcherEJB

Any ideas? Can you share more code, maybe I'm missing something?

[d92gunka]

I removed some code in order to make it more readable, but I think I removed a little to much

But if you add this to WatcherStopperEJB

@EJB
private WatcherEJB watcherEjb;

it should work.

[radekj_]

Thank you. Now there is no compiler errors! Unfortunatelly my server still hangs on shutdown and I have to kill it each time. Something is really wrong about this!

[wdfink]

Did you took a thread dump if the shutdown hung up? Maybe that will show where the server stuck

[radekj_]

Here is how it looks (jstack -F <pid> >> threaddumps.log) when the server is shutting down:

http://pastebin.com/raw.php?i=Qi2rmGrA

or

http://pastebin.com/raw.php?i=azTTFPUt