org.n52.sos.cache.quartz.QuartzCacheScheduler.java Source code

Java tutorial

Introduction

Here is the source code for org.n52.sos.cache.quartz.QuartzCacheScheduler.java

Source

/**
 * Copyright (C) 2012 52North Initiative for Geospatial Open Source Software GmbH
 *
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
 * You may obtain a copy of the License at
 *
 *     http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */
package org.n52.sos.cache.quartz;

import java.io.File;
import java.io.IOException;
import java.lang.Thread.State;
import java.util.Collections;
import java.util.Date;
import java.util.Deque;
import java.util.HashMap;
import java.util.HashSet;
import java.util.List;
import java.util.Map;
import java.util.Set;
import java.util.UUID;
import java.util.concurrent.ConcurrentLinkedDeque;
import java.util.concurrent.atomic.AtomicBoolean;

import org.joda.time.DateTime;
import org.joda.time.LocalTime;
import org.joda.time.MutableDateTime;
import org.n52.sos.cache.AbstractEntityCache;
import org.n52.sos.cache.CacheException;
import org.n52.sos.cache.AbstractCacheScheduler;
import org.n52.sos.db.AccessGDB;
import org.n52.util.logging.Logger;
import org.quartz.Job;
import org.quartz.JobExecutionContext;
import org.quartz.JobExecutionException;
import org.quartz.JobKey;
import org.quartz.Scheduler;
import org.quartz.SchedulerException;
import org.quartz.SimpleScheduleBuilder;
import org.quartz.Trigger;
import org.quartz.TriggerBuilder;
import org.quartz.impl.JobDetailImpl;
import org.quartz.impl.StdSchedulerFactory;
import org.quartz.spi.JobFactory;
import org.quartz.spi.TriggerFiredBundle;

public class QuartzCacheScheduler extends AbstractCacheScheduler {

    public static Logger LOGGER = Logger.getLogger(QuartzCacheScheduler.class.getName());

    public long lastSchedulerThread = Long.MIN_VALUE;

    private Scheduler quartz;

    private LocalJobFactory quartzFactory;

    private Deque<NamedJob> shutdownHooks = new ConcurrentLinkedDeque<>();

    //   @Override
    //   public List<AbstractEntityCache<?>> getCandidates() {
    //      List<AbstractEntityCache<?>> result = new ArrayList<>();
    //      try {
    //         result.add(new DummyCache());
    //      } catch (FileNotFoundException e) {
    //         LOGGER.warn(e.getMessage(), e);
    //      }
    //      return result;
    //   }

    public QuartzCacheScheduler(AccessGDB geoDB, boolean updateCacheOnStartup, LocalTime cacheUpdateTime) {
        super(geoDB, updateCacheOnStartup, cacheUpdateTime);

        try {
            this.quartz = new StdSchedulerFactory().getScheduler();
            this.quartzFactory = new LocalJobFactory();
            this.quartz.setJobFactory(this.quartzFactory);
            this.quartz.start();
        } catch (SchedulerException e) {
            LOGGER.warn("Could not initialize cache scheduling", e);
            return;
        }

        if (!updateCacheOnStartup) {
            LOGGER.info("Update cache on startup disabled!");
        } else {
            try {
                schedule(new UpdateCacheTask(getCandidates()), 0);
                //            List<AbstractEntityCache<?>> requiresUpdates = cacheUpdateRequired();
                //            if (!requiresUpdates.isEmpty()) {
                //               LOGGER.info(String.format("Cache update required for: %s", requiresUpdates.toString()));
                //               /*
                //                * now
                //                */
                //               schedule(new UpdateCacheTask(requiresUpdates), 0);   
                //            }
                //            else {
                //               LOGGER.info("No cache update required. Last update not longer ago than minutes "+FIFTEEN_MINS_MS/(1000*60));
                //            }
            } catch (SchedulerException e) {
                LOGGER.warn(e.getMessage(), e);
                LOGGER.warn("could not initialize cache. disabling scheduled updates.");
                return;
            }
        }

        MutableDateTime mdt = resolveNextScheduleDate(this.getCacheUpdateTime(), new DateTime());
        DateTime now = new DateTime();

        try {
            //         schedule(new UpdateCacheTask(getCandidates()), ONE_HOUR_MS,
            //               ONE_HOUR_MS);
            schedule(new UpdateCacheTask(getCandidates()), mdt.getMillis() - now.getMillis(), ONE_HOUR_MS * 24);
        } catch (SchedulerException e) {
            LOGGER.warn(e.getMessage(), e);
        }

        LOGGER.severe("Next scheduled cache update: " + mdt.toString());

        /*
         * start ONE monitoring after 1 minute and check if the .lock file
         * is older than 30 minutes -> an artifact .lock file!!
         */
        try {
            schedule(new MonitorCacheTask(ONE_HOUR_MS / 2), ONE_HOUR_MS / 60);
        } catch (SchedulerException e) {
            LOGGER.warn(e.getMessage(), e);
        }
    }

    private void schedule(NamedJob updateCacheTask, long delay) throws SchedulerException {
        schedule(updateCacheTask, delay, 0);
    }

    private void schedule(NamedJob job, long delay, long period) throws SchedulerException {
        JobDetailImpl jobDetail = new JobDetailImpl();
        jobDetail.setKey(new JobKey(job.getName()));
        jobDetail.setJobClass(job.getClass());

        this.quartzFactory.register(job.getName(), job, period == 0 ? false : true);

        TriggerBuilder<Trigger> builder = TriggerBuilder.newTrigger()
                .withIdentity(jobDetail.getKey().getName().concat("_trigger"));

        if (delay != 0) {
            Date delayDate = new Date();
            delayDate = new Date(delayDate.getTime() + delay);
            builder = builder.startAt(delayDate);
        } else {
            builder = builder.startNow();
        }

        if (period != 0) {
            builder.withSchedule(
                    SimpleScheduleBuilder.simpleSchedule().withIntervalInMilliseconds(period).repeatForever());
        }

        Trigger trigger = builder.build();

        try {
            this.quartz.scheduleJob(jobDetail, trigger);
            LOGGER.info(String.format("Added Job '%s' (%s) to scheduling. Next execution at %s; Recurring: %s",
                    jobDetail.getKey().getName(), job.getClass().getSimpleName(), trigger.getStartTime(), period));
        } catch (SchedulerException e) {
            LOGGER.warn(e.getMessage(), e);
            throw e;
        }
    }

    public void forceUpdate() {
        if (isCurrentyLocked()) {
            LOGGER.info("chache updating locked. skipping");
            return;
        } else {
            try {
                schedule(new UpdateCacheTask(getCandidates()), 0);
            } catch (SchedulerException e) {
                LOGGER.warn(e.getMessage(), e);
            }
        }
    }

    @Override
    public void shutdown() {
        try {
            this.quartz.shutdown();
            freeCacheUpdateLock();
            for (NamedJob s : this.shutdownHooks) {
                s.cancelExecution();
            }
        } catch (IOException | SchedulerException e) {
            LOGGER.warn(e.getMessage(), e);
        }
    }

    private String createStackTrace(StackTraceElement[] stackTrace) {
        if (stackTrace == null || stackTrace.length == 0) {
            return "";
        }

        StringBuilder sb = new StringBuilder();

        String sep = System.getProperty("line.separator");
        for (StackTraceElement ste : stackTrace) {
            sb.append(ste.toString());
            sb.append(sep);
        }

        return sb.toString();
    }

    private abstract class NamedJob implements Job {

        String uuid = UUID.randomUUID().toString();

        public String getName() {
            return uuid;
        }

        public abstract void cancelExecution();

    }

    private class UpdateCacheTask extends NamedJob {

        private List<AbstractEntityCache<?>> candidates;
        private boolean reschedulingAllowed;
        private AtomicBoolean running;
        private Thread updateThread;

        /**
         * Constructor, allowing rescheduling of failed cache updates
         * 
         * @param candidates the cache candidates
         */
        public UpdateCacheTask(List<AbstractEntityCache<?>> candidates) {
            this(candidates, true);
        }

        /**
         * @param candidates the cache candidates
         * @param reschedulingAllowed if an update fails, allow to reschedule
         * another one
         */
        public UpdateCacheTask(List<AbstractEntityCache<?>> candidates, boolean reschedulingAllowed) {
            this.candidates = candidates;
            this.reschedulingAllowed = reschedulingAllowed;
        }

        @Override
        public void execute(JobExecutionContext arg0) throws JobExecutionException {
            QuartzCacheScheduler.this.shutdownHooks.add(this);
            //         try {
            //            schedule(new MonitorCacheTask(ONE_HOUR_MS/2), ONE_HOUR_MS/2);
            //         } catch (SchedulerException e) {
            //            LOGGER.warn(e.getMessage(), e);
            //         }

            /*
             * do a cache.lock check now and do it sequentially
             */
            MonitorCacheTask freeTask = new MonitorCacheTask(ONE_HOUR_MS / 2);
            freeTask.execute(null);

            running = new AtomicBoolean(true);
            updateThread = new Thread(new Runnable() {

                @Override
                public void run() {
                    try {
                        doCacheUpdate();
                    } catch (RuntimeException e) {
                        LOGGER.warn(e.getMessage(), e);
                    } catch (Throwable t) {
                        LOGGER.warn(t.getMessage(), t);
                        running.getAndSet(false);
                        throw t;
                    }
                    running.getAndSet(false);
                }
            });

            updateThread.setDaemon(true);
            updateThread.start();

            long start = System.currentTimeMillis();
            while (running.get() && updateThread.getState() != Thread.State.TERMINATED) {
                if (System.currentTimeMillis() - start > 1000 * 60 * 30) {
                    cancelUpdateThread(updateThread);
                    break;
                } else {
                    LOGGER.info("still waiting for update thread to finish...");
                }

                try {
                    Thread.sleep(60000);
                } catch (InterruptedException e) {
                    LOGGER.warn(e.getMessage(), e);
                }
            }

            LOGGER.info("update thread finished...");
            logNextFireTime();

            QuartzCacheScheduler.this.shutdownHooks.remove(this);
        }

        @Override
        public void cancelExecution() {
            for (AbstractEntityCache<?> aec : this.candidates) {
                aec.cancelCurrentExecution();
            }
            this.running.getAndSet(false);
            cancelUpdateThread(updateThread);
        }

        private void cancelUpdateThread(Thread t) {
            Map<Thread, StackTraceElement[]> stacks = Collections.singletonMap(t, t.getStackTrace());

            LOGGER.warn("update thread took more than 30 minutes... cancelling.  StackTrace: "
                    + dumpAllThreads(stacks));

            try {
                t.interrupt();
                freeCacheUpdateLock();
            } catch (IOException e) {
                LOGGER.warn(e.getMessage(), e);
            }
        }

        private void logNextFireTime() {
            try {
                List<? extends Trigger> detail = quartz.getTriggersOfJob(new JobKey(getName()));
                if (detail != null && !detail.isEmpty()) {
                    Date next = detail.get(0).getNextFireTime();
                    if (next != null) {
                        LOGGER.info("Next scheduled cache update: " + next);
                    }
                }
            } catch (SchedulerException e) {
                LOGGER.warn(e.getMessage(), e);
            }
        }

        private void doCacheUpdate() {
            /*
             * cache updates can take very long. it has been observed
             * on some SOE instances that the update got stuck and did
             * not continue, leaving a stale cache.lock file behind.
             * 
             * this monitor takes care of cleaning up a staled lock file
             * after a certain amount of time
             */
            try {

                if (!retrieveCacheUpdateLock()) {
                    LOGGER.info("chache updating locked. skipping");
                    return;
                }

                QuartzCacheScheduler.this.lastSchedulerThread = Thread.currentThread().getId();
                LOGGER.info("update cache... using thread " + lastSchedulerThread);

                for (AbstractEntityCache<?> aec : this.candidates) {
                    try {
                        aec.updateCache(getGeoDB());
                    } catch (CacheException e) {
                        LOGGER.warn("Cache update exception for Cache " + aec.getClass().getName(), e);
                    }
                }

                LOGGER.info("all caches updated!");
            } catch (IOException | RuntimeException e) {
                LOGGER.warn("Cache update cancelled due to exception.", e);

                /*
                 * are we allowed to reschedule another update?
                 * If a (daily) update fails once, we try another
                 * one after 30 minutes
                 */
                if (this.reschedulingAllowed) {
                    LOGGER.info("rescheduling cache update...");
                    try {
                        schedule(new UpdateCacheTask(candidates, false), ONE_HOUR_MS / 2);
                    } catch (SchedulerException e1) {
                        LOGGER.warn(e.getMessage(), e);
                    }
                }
            } catch (Throwable t) {
                LOGGER.severe("Unrecoverable error", t);
                throw t;
            } finally {
                try {
                    freeCacheUpdateLock();
                } catch (IOException e) {
                    LOGGER.warn(e.getMessage(), e);
                }
            }
        }

    }

    private class MonitorCacheTask extends NamedJob {

        private long maximumAge = Long.MIN_VALUE;

        /**
         * @param maximumAge delete only a file that is older than this age
         */
        public MonitorCacheTask(long maximumAge) {
            this.maximumAge = maximumAge;
        }

        @Override
        public void execute(JobExecutionContext arg0) throws JobExecutionException {
            LOGGER.info(String.format("Monitoring cache update using thread %s; considers .lock age? %s",
                    Thread.currentThread().getId(), maximumAge != Long.MIN_VALUE));

            Map<Thread, StackTraceElement[]> stacks = Thread.getAllStackTraces();

            Thread target = null;

            /*
             * try to find the 
             */
            if (QuartzCacheScheduler.this.lastSchedulerThread != Long.MIN_VALUE) {
                for (Thread t : stacks.keySet()) {
                    if (t.getId() == QuartzCacheScheduler.this.lastSchedulerThread) {
                        target = t;
                        break;
                    }
                }
            }

            if (target != null) {
                State state = target.getState();
                LOGGER.info("lastSchedulerThread status: " + state);
                LOGGER.info("lastSchedulerThread isalive: " + target.isAlive());
                LOGGER.info("lastSchedulerThread isinterrupted: " + target.isInterrupted());

                if (state != State.RUNNABLE && state != State.BLOCKED) {
                    LOGGER.info(
                            String.format("Updater thread's stack: %s", createStackTrace(target.getStackTrace())));
                }
            } else {
                LOGGER.info("Could not find lastSchedulerThread in current stack traces");
            }

            boolean isLocked = true;

            isLocked = isCurrentyLocked();
            if (isLocked) {
                //            if (target != null && (target.getState() == Thread.State.TIMED_WAITING
                //                  || target.getState() == Thread.State.WAITING)) {
                //               LOGGER.warn("The cache update may have taken too long. trying to interrupt cache update.");
                //               target.interrupt();
                //            }

                //            
                //            dumpAllThreads(stacks);

                try {
                    if (this.maximumAge != Long.MIN_VALUE) {
                        LOGGER.info("Resolving age of cache.lock file");
                        File f = resolveCacheLockFile();
                        if (System.currentTimeMillis() - f.lastModified() > this.maximumAge) {
                            LOGGER.info("Trying to remove artifact cache.lock file due to its age");
                            freeCacheUpdateLock();
                        } else {
                            LOGGER.info("cache.lock to young, an update might be in progress.");
                        }
                    } else if (QuartzCacheScheduler.this.lastSchedulerThread != Long.MIN_VALUE) {
                        /*
                         * only free if this QuartzCacheScheduler instance (singleton in an SOE instance)
                         * has already started a cache update. otherwise lastSchedulerThread has
                         * not been set yet
                         */
                        LOGGER.info("freeing cache.lock");
                        freeCacheUpdateLock();
                    }
                } catch (IOException e) {
                    LOGGER.warn(e.getMessage(), e);
                }

            } else {
                LOGGER.info("No stale cache.lock file found.");
            }

        }

        @Override
        public void cancelExecution() {
        }

    }

    private class LocalJobFactory implements JobFactory {

        private final Map<String, Job> jobs = new HashMap<>();
        private final Set<String> recurring = new HashSet<>();

        @Override
        public synchronized Job newJob(TriggerFiredBundle bundle, Scheduler scheduler) throws SchedulerException {
            String name = bundle.getJobDetail().getKey().getName();
            Job result = jobs.get(name);

            if (!recurring.contains(name)) {
                jobs.remove(name);
            }

            return result;
        }

        public synchronized void register(String name, Job job, boolean recurring) {
            jobs.put(name, job);
            if (recurring) {
                this.recurring.add(name);
            }
        }

    }

    protected String dumpAllThreads(Map<Thread, StackTraceElement[]> stacks) {
        StringBuilder sb = new StringBuilder();
        String sep = System.getProperty("line.separator");

        for (Thread t : stacks.keySet()) {
            sb.append("###### ");
            sb.append(new DateTime().toString());
            sb.append(sep);
            sb.append(t.getName() + " " + t.getId() + " " + t.getState());
            sb.append(sep);
            for (StackTraceElement ste : stacks.get(t)) {
                sb.append(ste.toString());
                sb.append(sep);
            }
            sb.append(sep);
        }

        return sb.toString();
    }

}