@BeforeMethod(alwaysRun = true) public void setUp() throws Exception { currentTime = new AtomicLong(System.currentTimeMillis()); ticker = new Ticker() { // strictly not a ticker because returns millis UTC, but it works fine even so @Override public long read() { return currentTime.get(); } }; promotionListener = new RecordingPromotionListener(); managementContext = newLocalManagementContext(); ownNodeId = managementContext.getManagementNodeId(); objectStore = newPersistenceObjectStore(); objectStore.injectManagementContext(managementContext); objectStore.prepareForUse(PersistMode.CLEAN, HighAvailabilityMode.DISABLED); persister = new ManagementPlaneSyncRecordPersisterToObjectStore( managementContext, objectStore, classLoader); BrooklynMementoPersisterToObjectStore persisterObj = new BrooklynMementoPersisterToObjectStore(objectStore, classLoader); managementContext.getRebindManager().setPersister(persisterObj); manager = new HighAvailabilityManagerImpl(managementContext) .setPollPeriod(Duration.millis(10)) .setHeartbeatTimeout(Duration.THIRTY_SECONDS) .setPromotionListener(promotionListener) .setTicker(ticker) .setPersister(persister); }
@Test public void testCancelled() throws InterruptedException, ExecutionException { Task<List<?>> t = Tasks.sequential(sayTask("1"), sayTask("2a", Duration.THIRTY_SECONDS, "2b"), sayTask("3")); ec.submit(t); synchronized (messages) { while (messages.size() <= 1) messages.wait(); } Assert.assertEquals(messages, Arrays.asList("1", "2a")); Time.sleep(Duration.millis(50)); t.cancel(true); Assert.assertTrue(t.isDone()); // 2 should get cancelled, and invoke the cancellation semaphore // 3 should get cancelled and not run at all Assert.assertEquals(messages, Arrays.asList("1", "2a")); // Need to ensure that 2 has been started; race where we might cancel it before its run method // is even begun. Hence doing "2a; pause; 2b" where nothing is interruptable before pause. Assert.assertTrue(cancellations.tryAcquire(10, TimeUnit.SECONDS)); Iterator<Task<?>> ci = ((HasTaskChildren) t).getChildren().iterator(); Assert.assertEquals(ci.next().get(), "1"); Task<?> task2 = ci.next(); Assert.assertTrue(task2.isBegun()); Assert.assertTrue(task2.isDone()); Assert.assertTrue(task2.isCancelled()); Task<?> task3 = ci.next(); Assert.assertFalse(task3.isBegun()); Assert.assertTrue(task2.isDone()); Assert.assertTrue(task2.isCancelled()); // but we do _not_ get a mutex from task3 as it does not run (is not interrupted) Assert.assertEquals(cancellations.availablePermits(), 0); }
protected ManagementContext newPersistingManagementContext() { mementoDir = Os.newTempDir(JavaClassNames.cleanSimpleClassName(this)); Os.deleteOnExitRecursively(mementoDir); return RebindTestUtils.managementContextBuilder( classLoader, new FileBasedObjectStore(mementoDir)) .persistPeriod(Duration.millis(10)) .buildStarted(); }
// The web-console could still be polling (e.g. if have just restarted brooklyn), before the // persister is set. // Must not throw NPE, but instead return something sensible (e.g. an empty state record). @Test public void testGetManagementPlaneSyncStateDoesNotThrowNpeBeforePersisterSet() throws Exception { HighAvailabilityManagerImpl manager2 = new HighAvailabilityManagerImpl(managementContext) .setPollPeriod(Duration.millis(10)) .setHeartbeatTimeout(Duration.THIRTY_SECONDS) .setPromotionListener(promotionListener) .setTicker(ticker); try { ManagementPlaneSyncRecord state = manager2.getManagementPlaneSyncState(); assertNotNull(state); } finally { manager2.stop(); } }
/** * Handler for when polling an entity's attribute. On each poll result the entity's attribute is * set. * * <p>Calls to onSuccess and onError will happen sequentially, but may be called from different * threads each time. Note that no guarantees of a synchronized block exist, so additional * synchronization would be required for the Java memory model's "happens before" relationship. * * @author aled */ public class AttributePollHandler<V> implements PollHandler<V> { public static final Logger log = LoggerFactory.getLogger(AttributePollHandler.class); private final FeedConfig<V, ?, ?> config; private final EntityLocal entity; @SuppressWarnings("rawtypes") private final AttributeSensor sensor; private final AbstractFeed feed; // allow 30 seconds before logging at WARN, if there has been no success yet; // after success WARN immediately // TODO these should both be configurable private Duration logWarningGraceTimeOnStartup = Duration.THIRTY_SECONDS; private Duration logWarningGraceTime = Duration.millis(0); // internal state to look after whether to log warnings private volatile Long lastSuccessTime = null; private volatile Long currentProblemStartTime = null; private volatile boolean currentProblemLoggedAsWarning = false; private volatile boolean lastWasProblem = false; public AttributePollHandler(FeedConfig<V, ?, ?> config, EntityLocal entity, AbstractFeed feed) { this.config = checkNotNull(config, "config"); this.entity = checkNotNull(entity, "entity"); this.sensor = checkNotNull(config.getSensor(), "sensor"); this.feed = checkNotNull(feed, "feed"); } @Override public boolean checkSuccess(V val) { // Always true if no checkSuccess predicate was configured. return !config.hasCheckSuccessHandler() || config.getCheckSuccess().apply(val); } @SuppressWarnings("unchecked") @Override public void onSuccess(V val) { if (lastWasProblem) { if (currentProblemLoggedAsWarning) { log.info("Success (following previous problem) reading " + entity + "->" + sensor); } else { log.debug("Success (following previous problem) reading " + entity + "->" + sensor); } lastWasProblem = false; currentProblemStartTime = null; currentProblemLoggedAsWarning = false; } lastSuccessTime = System.currentTimeMillis(); if (log.isTraceEnabled()) log.trace("poll for {}->{} got: {}", new Object[] {entity, sensor, val}); try { Object v = transformValue(val); if (v != PollConfig.UNSET) { entity.setAttribute(sensor, v); } } catch (Exception e) { if (feed.isConnected()) { log.warn("unable to compute " + entity + "->" + sensor + "; on val=" + val, e); } else { if (log.isDebugEnabled()) log.debug( "unable to compute " + entity + " ->" + sensor + "; val=" + val + " (when inactive)", e); } } } @SuppressWarnings("unchecked") @Override public void onFailure(V val) { if (!config.hasFailureHandler()) { onException( new Exception( "checkSuccess of " + this + " from " + entity + " was false but poller has no failure handler")); } else { logProblem("failure", val); try { Object v = coerce(config.getOnFailure().apply(val)); if (v != PollConfig.UNSET) { entity.setAttribute(sensor, v); } } catch (Exception e) { if (feed.isConnected()) { log.warn("Error computing " + entity + "->" + sensor + "; val=" + val + ": " + e, e); } else { if (log.isDebugEnabled()) log.debug( "Error computing " + entity + " ->" + sensor + "; val=" + val + " (when inactive)", e); } } } } @SuppressWarnings("unchecked") @Override public void onException(Exception exception) { if (!feed.isConnected()) { if (log.isDebugEnabled()) log.debug( "Read of {} from {} gave exception (while not connected or not yet connected): {}", new Object[] {this, entity, exception}); } else { logProblem("exception", exception); } if (config.hasExceptionHandler()) { try { Object v = transformError(exception); if (v != PollConfig.UNSET) { entity.setAttribute(sensor, v); } } catch (Exception e) { if (feed.isConnected()) { log.warn( "unable to compute " + entity + "->" + sensor + "; on exception=" + exception, e); } else { if (log.isDebugEnabled()) log.debug( "unable to compute " + entity + " ->" + sensor + "; exception=" + exception + " (when inactive)", e); } } } } protected void logProblem(String type, Object val) { if (lastWasProblem && currentProblemLoggedAsWarning) { if (log.isDebugEnabled()) log.debug("Recurring " + type + " reading " + this + " from " + entity + ": " + val); } else { long nowTime = System.currentTimeMillis(); // get a non-volatile value Long currentProblemStartTimeCache = currentProblemStartTime; long expiryTime = lastSuccessTime != null ? lastSuccessTime + logWarningGraceTime.toMilliseconds() : currentProblemStartTimeCache != null ? currentProblemStartTimeCache + logWarningGraceTimeOnStartup.toMilliseconds() : nowTime + logWarningGraceTimeOnStartup.toMilliseconds(); if (!lastWasProblem) { if (expiryTime <= nowTime) { currentProblemLoggedAsWarning = true; log.warn("Read of " + entity + "->" + sensor + " gave " + type + ": " + val); if (log.isDebugEnabled() && val instanceof Throwable) log.debug( "Trace for " + type + " reading " + entity + "->" + sensor + ": " + val, (Throwable) val); } else { if (log.isDebugEnabled()) log.debug( "Read of " + entity + "->" + sensor + " gave " + type + " (in grace period)" + ": " + val); } lastWasProblem = true; currentProblemStartTime = nowTime; } else { if (expiryTime <= nowTime) { currentProblemLoggedAsWarning = true; log.warn( "Read of " + entity + "->" + sensor + " gave " + type + " (grace period expired, occurring for " + Duration.millis(nowTime - currentProblemStartTimeCache) + ")" + ": " + val); if (log.isDebugEnabled() && val instanceof Throwable) log.debug( "Trace for " + type + " reading " + entity + "->" + sensor + ": " + val, (Throwable) val); } else { log.debug( "Recurring " + type + " reading " + this + " from " + entity + " (still in grace period)" + ": " + val); } } } } /** * Does post-processing on the result of the actual poll, to convert it to the attribute's new * value. Or returns PollConfig.UNSET if the post-processing indicates that the attribute should * not be changed. */ @SuppressWarnings("unchecked") protected Object transformValue(Object val) { if (config.hasSuccessHandler()) { return coerce(config.getOnSuccess().apply((V) val)); } else { return coerce(val); } } /** * Does post-processing on a poll error, to convert it to the attribute's new value. Or returns * PollConfig.UNSET if the post-processing indicates that the attribute should not be changed. */ protected Object transformError(Exception error) throws Exception { if (!config.hasExceptionHandler()) throw new IllegalStateException( "Attribute poll handler has no error handler, but attempted to transform error", error); return coerce(config.getOnException().apply(error)); } @SuppressWarnings("unchecked") private Object coerce(Object v) { if (v != PollConfig.UNSET) { return TypeCoercions.coerce(v, sensor.getType()); } else { return v; } } @Override public String toString() { return super.toString() + "[" + getDescription() + "]"; } @Override public String getDescription() { return sensor.getName() + " @ " + entity.getId() + " <- " + config; } }
protected void logProblem(String type, Object val) { if (lastWasProblem && currentProblemLoggedAsWarning) { if (log.isDebugEnabled()) log.debug("Recurring " + type + " reading " + this + " from " + entity + ": " + val); } else { long nowTime = System.currentTimeMillis(); // get a non-volatile value Long currentProblemStartTimeCache = currentProblemStartTime; long expiryTime = lastSuccessTime != null ? lastSuccessTime + logWarningGraceTime.toMilliseconds() : currentProblemStartTimeCache != null ? currentProblemStartTimeCache + logWarningGraceTimeOnStartup.toMilliseconds() : nowTime + logWarningGraceTimeOnStartup.toMilliseconds(); if (!lastWasProblem) { if (expiryTime <= nowTime) { currentProblemLoggedAsWarning = true; log.warn("Read of " + entity + "->" + sensor + " gave " + type + ": " + val); if (log.isDebugEnabled() && val instanceof Throwable) log.debug( "Trace for " + type + " reading " + entity + "->" + sensor + ": " + val, (Throwable) val); } else { if (log.isDebugEnabled()) log.debug( "Read of " + entity + "->" + sensor + " gave " + type + " (in grace period)" + ": " + val); } lastWasProblem = true; currentProblemStartTime = nowTime; } else { if (expiryTime <= nowTime) { currentProblemLoggedAsWarning = true; log.warn( "Read of " + entity + "->" + sensor + " gave " + type + " (grace period expired, occurring for " + Duration.millis(nowTime - currentProblemStartTimeCache) + ")" + ": " + val); if (log.isDebugEnabled() && val instanceof Throwable) log.debug( "Trace for " + type + " reading " + entity + "->" + sensor + ": " + val, (Throwable) val); } else { log.debug( "Recurring " + type + " reading " + this + " from " + entity + " (still in grace period)" + ": " + val); } } } }
public void scheduleAtFixedRate(Callable<V> job, PollHandler<? super V> handler, long period) { scheduleAtFixedRate(job, handler, Duration.millis(period)); }
/** @see #getMxBeanSensorsBuilder(EntityLocal, Duration) */ @Nonnull public static JmxFeed.Builder getMxBeanSensorsBuilder(EntityLocal entity, long jmxPollPeriod) { return getMxBeanSensorsBuilder(entity, Duration.millis(jmxPollPeriod)); }
public static class Builder { private EntityLocal entity; private boolean onlyIfServiceUp = false; private Supplier<URI> baseUriProvider; private Duration period = Duration.millis(500); private List<HttpPollConfig<?>> polls = Lists.newArrayList(); private URI baseUri; private Map<String, String> baseUriVars = Maps.newLinkedHashMap(); private Map<String, String> headers = Maps.newLinkedHashMap(); private boolean suspended = false; private Credentials credentials; private volatile boolean built; public Builder entity(EntityLocal val) { this.entity = val; return this; } public Builder onlyIfServiceUp() { return onlyIfServiceUp(true); } public Builder onlyIfServiceUp(boolean onlyIfServiceUp) { this.onlyIfServiceUp = onlyIfServiceUp; return this; } public Builder baseUri(Supplier<URI> val) { if (baseUri != null && val != null) throw new IllegalStateException("Builder cannot take both a URI and a URI Provider"); this.baseUriProvider = val; return this; } public Builder baseUri(URI val) { if (baseUriProvider != null && val != null) throw new IllegalStateException("Builder cannot take both a URI and a URI Provider"); this.baseUri = val; return this; } public Builder baseUrl(URL val) { return baseUri(URI.create(val.toString())); } public Builder baseUri(String val) { return baseUri(URI.create(val)); } public Builder baseUriVars(Map<String, String> vals) { baseUriVars.putAll(vals); return this; } public Builder baseUriVar(String key, String val) { baseUriVars.put(key, val); return this; } public Builder headers(Map<String, String> vals) { headers.putAll(vals); return this; } public Builder header(String key, String val) { headers.put(key, val); return this; } public Builder period(Duration duration) { this.period = duration; return this; } public Builder period(long millis) { return period(millis, TimeUnit.MILLISECONDS); } public Builder period(long val, TimeUnit units) { return period(Duration.of(val, units)); } public Builder poll(HttpPollConfig<?> config) { polls.add(config); return this; } public Builder suspended() { return suspended(true); } public Builder suspended(boolean startsSuspended) { this.suspended = startsSuspended; return this; } public Builder credentials(String username, String password) { this.credentials = new UsernamePasswordCredentials(username, password); return this; } public Builder credentialsIfNotNull(String username, String password) { if (username != null) { this.credentials = new UsernamePasswordCredentials(username, password); } return this; } public HttpFeed build() { built = true; HttpFeed result = new HttpFeed(this); if (suspended) result.suspend(); result.start(); return result; } @Override protected void finalize() { if (!built) log.warn("HttpFeed.Builder created, but build() never called"); } }
public class DynamicSequentialTaskTest { private static final Logger log = LoggerFactory.getLogger(DynamicSequentialTaskTest.class); public static final Duration TIMEOUT = Duration.TEN_SECONDS; public static final Duration TINY_TIME = Duration.millis(20); BasicExecutionManager em; BasicExecutionContext ec; List<String> messages; Semaphore cancellations; Stopwatch stopwatch; Map<String, Semaphore> monitorableJobSemaphoreMap; Map<String, Task<String>> monitorableTasksMap; @BeforeMethod(alwaysRun = true) public void setUp() { em = new BasicExecutionManager("mycontext"); ec = new BasicExecutionContext(em); cancellations = new Semaphore(0); messages = new ArrayList<String>(); monitorableJobSemaphoreMap = MutableMap.of(); monitorableTasksMap = MutableMap.of(); monitorableTasksMap.clear(); stopwatch = Stopwatch.createStarted(); } @AfterMethod(alwaysRun = true) public void tearDown() throws Exception { if (em != null) em.shutdownNow(); } @Test public void testSimple() throws InterruptedException, ExecutionException { Callable<String> mainJob = new Callable<String>() { public String call() { log.info("main job - " + Tasks.current()); messages.add("main"); DynamicTasks.queue(sayTask("world")); return "bye"; } }; DynamicSequentialTask<String> t = new DynamicSequentialTask<String>(mainJob); // this should be added before anything added when the task is invoked t.queue(sayTask("hello")); Assert.assertEquals(messages, Lists.newArrayList()); Assert.assertEquals(t.isBegun(), false); Assert.assertEquals(Iterables.size(t.getChildren()), 1); ec.submit(t); Assert.assertEquals(t.isSubmitted(), true); Assert.assertEquals(t.getUnchecked(Duration.ONE_SECOND), "bye"); long elapsed = t.getEndTimeUtc() - t.getSubmitTimeUtc(); Assert.assertTrue( elapsed < 1000, "elapsed time should have been less than 1s but was " + Time.makeTimeString(elapsed, true)); Assert.assertEquals(Iterables.size(t.getChildren()), 2); Assert.assertEquals(messages.size(), 3, "expected 3 entries, but had " + messages); // either main or hello can be first, but world should be last Assert.assertEquals(messages.get(2), "world"); } public Callable<String> sayCallable( final String message, final Duration duration, final String message2) { return new Callable<String>() { public String call() { try { if (message != null) { log.info("saying: " + message + " - " + Tasks.current()); synchronized (messages) { messages.add(message); messages.notifyAll(); } } if (message2 != null) { log.info("will say " + message2 + " after " + duration); } if (duration != null && duration.toMilliseconds() > 0) { Thread.sleep(duration.toMillisecondsRoundingUp()); } } catch (InterruptedException e) { cancellations.release(); throw Exceptions.propagate(e); } if (message2 != null) { log.info("saying: " + message2 + " - " + Tasks.current()); synchronized (messages) { messages.add(message2); messages.notifyAll(); } } return message; } }; } public Task<String> sayTask(String message) { return sayTask(message, null, null); } public Task<String> sayTask(String message, Duration duration, String message2) { return Tasks.<String>builder().body(sayCallable(message, duration, message2)).build(); } @Test public void testComplex() throws InterruptedException, ExecutionException { Task<List<?>> t = Tasks.sequential( sayTask("1"), sayTask("2"), Tasks.parallel(sayTask("4"), sayTask("3")), sayTask("5")); ec.submit(t); Assert.assertEquals(t.get().size(), 4); Asserts.assertEqualsIgnoringOrder((List<?>) t.get().get(2), ImmutableSet.of("3", "4")); Assert.assertTrue( messages.equals(Arrays.asList("1", "2", "3", "4", "5")) || messages.equals(Arrays.asList("1", "2", "4", "3", "5")), "messages=" + messages); } @Test public void testCancelled() throws InterruptedException, ExecutionException { Task<List<?>> t = Tasks.sequential(sayTask("1"), sayTask("2a", Duration.THIRTY_SECONDS, "2b"), sayTask("3")); ec.submit(t); synchronized (messages) { while (messages.size() <= 1) messages.wait(); } Assert.assertEquals(messages, Arrays.asList("1", "2a")); Time.sleep(Duration.millis(50)); t.cancel(true); Assert.assertTrue(t.isDone()); // 2 should get cancelled, and invoke the cancellation semaphore // 3 should get cancelled and not run at all Assert.assertEquals(messages, Arrays.asList("1", "2a")); // Need to ensure that 2 has been started; race where we might cancel it before its run method // is even begun. Hence doing "2a; pause; 2b" where nothing is interruptable before pause. Assert.assertTrue(cancellations.tryAcquire(10, TimeUnit.SECONDS)); Iterator<Task<?>> ci = ((HasTaskChildren) t).getChildren().iterator(); Assert.assertEquals(ci.next().get(), "1"); Task<?> task2 = ci.next(); Assert.assertTrue(task2.isBegun()); Assert.assertTrue(task2.isDone()); Assert.assertTrue(task2.isCancelled()); Task<?> task3 = ci.next(); Assert.assertFalse(task3.isBegun()); Assert.assertTrue(task2.isDone()); Assert.assertTrue(task2.isCancelled()); // but we do _not_ get a mutex from task3 as it does not run (is not interrupted) Assert.assertEquals(cancellations.availablePermits(), 0); } protected Task<String> monitorableTask(final String id) { return monitorableTask(null, id, null); } protected Task<String> monitorableTask( final Runnable pre, final String id, final Callable<String> post) { Task<String> t = Tasks.<String>builder().body(monitorableJob(pre, id, post)).build(); monitorableTasksMap.put(id, t); return t; } protected Callable<String> monitorableJob(final String id) { return monitorableJob(null, id, null); } protected Callable<String> monitorableJob( final Runnable pre, final String id, final Callable<String> post) { monitorableJobSemaphoreMap.put(id, new Semaphore(0)); return new Callable<String>() { @Override public String call() throws Exception { if (pre != null) pre.run(); // wait for semaphore if (!monitorableJobSemaphoreMap .get(id) .tryAcquire(1, TIMEOUT.toMilliseconds(), TimeUnit.MILLISECONDS)) throw new IllegalStateException("timeout for " + id); synchronized (messages) { messages.add(id); messages.notifyAll(); } if (post != null) return post.call(); return id; } }; } protected void releaseMonitorableJob(final String id) { monitorableJobSemaphoreMap.get(id).release(); } protected void waitForMessage(final String id) { CountdownTimer timer = CountdownTimer.newInstanceStarted(TIMEOUT); synchronized (messages) { while (!timer.isExpired()) { if (messages.contains(id)) return; timer.waitOnForExpiryUnchecked(messages); } } Assert.fail("Did not see message " + id); } protected void releaseAndWaitForMonitorableJob(final String id) { releaseMonitorableJob(id); waitForMessage(id); } @Test public void testChildrenRunConcurrentlyWithPrimary() { Task<String> t = Tasks.<String>builder() .dynamic(true) .body(monitorableJob("main")) .add(monitorableTask("1")) .add(monitorableTask("2")) .build(); ec.submit(t); releaseAndWaitForMonitorableJob("1"); releaseAndWaitForMonitorableJob("main"); Assert.assertFalse(t.blockUntilEnded(TINY_TIME)); releaseMonitorableJob("2"); Assert.assertTrue(t.blockUntilEnded(TIMEOUT)); Assert.assertEquals(messages, MutableList.of("1", "main", "2")); Assert.assertTrue( stopwatch.elapsed(TimeUnit.MILLISECONDS) < TIMEOUT.toMilliseconds(), "took too long: " + stopwatch); Assert.assertFalse(t.isError()); } protected static class FailRunnable implements Runnable { @Override public void run() { throw new RuntimeException("Planned exception for test"); } } protected static class FailCallable implements Callable<String> { @Override public String call() { throw new RuntimeException("Planned exception for test"); } } @Test public void testByDefaultChildrenFailureAbortsSecondaryFailsPrimaryButNotAbortsPrimary() { Task<String> t1 = monitorableTask(null, "1", new FailCallable()); Task<String> t = Tasks.<String>builder() .dynamic(true) .body(monitorableJob("main")) .add(t1) .add(monitorableTask("2")) .build(); ec.submit(t); releaseAndWaitForMonitorableJob("1"); Assert.assertFalse(t.blockUntilEnded(TINY_TIME)); releaseMonitorableJob("main"); Assert.assertTrue(t.blockUntilEnded(TIMEOUT)); Assert.assertEquals(messages, MutableList.of("1", "main")); Assert.assertTrue( stopwatch.elapsed(TimeUnit.MILLISECONDS) < TIMEOUT.toMilliseconds(), "took too long: " + stopwatch); Assert.assertTrue(t.isError()); Assert.assertTrue(t1.isError()); } @Test public void testWhenSwallowingChildrenFailureDoesNotAbortSecondaryOrFailPrimary() { Task<String> t1 = monitorableTask(null, "1", new FailCallable()); Task<String> t = Tasks.<String>builder() .dynamic(true) .body(monitorableJob("main")) .add(t1) .add(monitorableTask("2")) .swallowChildrenFailures(true) .build(); ec.submit(t); releaseAndWaitForMonitorableJob("1"); Assert.assertFalse(t.blockUntilEnded(TINY_TIME)); releaseAndWaitForMonitorableJob("2"); Assert.assertFalse(t.blockUntilEnded(TINY_TIME)); releaseMonitorableJob("main"); Assert.assertTrue(t.blockUntilEnded(TIMEOUT)); Assert.assertEquals(messages, MutableList.of("1", "2", "main")); Assert.assertTrue( stopwatch.elapsed(TimeUnit.MILLISECONDS) < TIMEOUT.toMilliseconds(), "took too long: " + stopwatch); Assert.assertFalse(t.isError()); Assert.assertTrue(t1.isError()); } @Test public void testInessentialChildrenFailureDoesNotAbortSecondaryOrFailPrimary() { Task<String> t1 = monitorableTask(null, "1", new FailCallable()); TaskTags.markInessential(t1); Task<String> t = Tasks.<String>builder() .dynamic(true) .body(monitorableJob("main")) .add(t1) .add(monitorableTask("2")) .build(); ec.submit(t); releaseAndWaitForMonitorableJob("1"); Assert.assertFalse(t.blockUntilEnded(TINY_TIME)); releaseAndWaitForMonitorableJob("2"); Assert.assertFalse(t.blockUntilEnded(TINY_TIME)); releaseMonitorableJob("main"); Assert.assertTrue(t.blockUntilEnded(TIMEOUT)); Assert.assertEquals(messages, MutableList.of("1", "2", "main")); Assert.assertTrue( stopwatch.elapsed(TimeUnit.MILLISECONDS) < TIMEOUT.toMilliseconds(), "took too long: " + stopwatch); Assert.assertFalse(t.isError()); Assert.assertTrue(t1.isError()); } @Test public void testTaskBuilderUsingAddVarargChildren() { Task<String> t = Tasks.<String>builder() .dynamic(true) .body(monitorableJob("main")) .add(monitorableTask("1"), monitorableTask("2")) .build(); ec.submit(t); releaseAndWaitForMonitorableJob("1"); releaseAndWaitForMonitorableJob("2"); releaseAndWaitForMonitorableJob("main"); Assert.assertEquals(messages, MutableList.of("1", "2", "main")); } @Test public void testTaskBuilderUsingAddAllChildren() { Task<String> t = Tasks.<String>builder() .dynamic(true) .body(monitorableJob("main")) .addAll(ImmutableList.of(monitorableTask("1"), monitorableTask("2"))) .build(); ec.submit(t); releaseAndWaitForMonitorableJob("1"); releaseAndWaitForMonitorableJob("2"); releaseAndWaitForMonitorableJob("main"); Assert.assertEquals(messages, MutableList.of("1", "2", "main")); } }
/** * Handler for when polling an entity's attribute. On each poll result the entity's attribute is * set. * * <p>Calls to onSuccess and onError will happen sequentially, but may be called from different * threads each time. Note that no guarantees of a synchronized block exist, so additional * synchronization would be required for the Java memory model's "happens before" relationship. * * @author aled */ public class AttributePollHandler<V> implements PollHandler<V> { public static final Logger log = LoggerFactory.getLogger(AttributePollHandler.class); private final FeedConfig<V, ?, ?> config; private final EntityLocal entity; @SuppressWarnings("rawtypes") private final AttributeSensor sensor; private final AbstractFeed feed; // allow 30 seconds before logging at WARN, if there has been no success yet; // after success WARN immediately // TODO these should both be configurable private Duration logWarningGraceTimeOnStartup = Duration.THIRTY_SECONDS; private Duration logWarningGraceTime = Duration.millis(0); // internal state to look after whether to log warnings private volatile Long lastSuccessTime = null; private volatile Long currentProblemStartTime = null; private volatile boolean currentProblemLoggedAsWarning = false; private volatile boolean lastWasProblem = false; public AttributePollHandler(FeedConfig<V, ?, ?> config, EntityLocal entity, AbstractFeed feed) { this.config = checkNotNull(config, "config"); this.entity = checkNotNull(entity, "entity"); this.sensor = checkNotNull(config.getSensor(), "sensor"); this.feed = checkNotNull(feed, "feed"); } @Override public boolean checkSuccess(V val) { // Always true if no checkSuccess predicate was configured. return !config.hasCheckSuccessHandler() || config.getCheckSuccess().apply(val); } @Override public void onSuccess(V val) { if (lastWasProblem) { if (currentProblemLoggedAsWarning) { log.info("Success (following previous problem) reading " + getBriefDescription()); } else { log.debug("Success (following previous problem) reading " + getBriefDescription()); } lastWasProblem = false; currentProblemStartTime = null; currentProblemLoggedAsWarning = false; } lastSuccessTime = System.currentTimeMillis(); if (log.isTraceEnabled()) log.trace("poll for {} got: {}", new Object[] {getBriefDescription(), val}); try { setSensor(transformValueOnSuccess(val)); } catch (Exception e) { if (feed.isConnected()) { log.warn("unable to compute " + getBriefDescription() + "; on val=" + val, e); } else { if (log.isDebugEnabled()) log.debug( "unable to compute " + getBriefDescription() + "; val=" + val + " (when inactive)", e); } } } /** * allows post-processing, such as applying a success handler; default applies the onSuccess * handler (which is recommended) */ protected Object transformValueOnSuccess(V val) { return config.hasSuccessHandler() ? config.getOnSuccess().apply(val) : val; } @Override public void onFailure(V val) { if (!config.hasFailureHandler()) { onException( new Exception( "checkSuccess of " + this + " for " + getBriefDescription() + " was false but poller has no failure handler")); } else { logProblem("failure", val); try { setSensor(config.hasFailureHandler() ? config.getOnFailure().apply((V) val) : val); } catch (Exception e) { if (feed.isConnected()) { log.warn("Error computing " + getBriefDescription() + "; val=" + val + ": " + e, e); } else { if (log.isDebugEnabled()) log.debug( "Error computing " + getBriefDescription() + "; val=" + val + " (when inactive)", e); } } } } @Override public void onException(Exception exception) { if (!feed.isConnected()) { if (log.isTraceEnabled()) log.trace( "Read of {} in {} gave exception (while not connected or not yet connected): {}", new Object[] {this, getBriefDescription(), exception}); } else { logProblem("exception", exception); } if (config.hasExceptionHandler()) { try { setSensor(config.getOnException().apply(exception)); } catch (Exception e) { if (feed.isConnected()) { log.warn("unable to compute " + getBriefDescription() + "; on exception=" + exception, e); } else { if (log.isDebugEnabled()) log.debug( "unable to compute " + getBriefDescription() + "; exception=" + exception + " (when inactive)", e); } } } } protected void logProblem(String type, Object val) { if (lastWasProblem && currentProblemLoggedAsWarning) { if (log.isTraceEnabled()) log.trace( "Recurring {} reading {} in {}: {}", new Object[] {type, this, getBriefDescription(), val}); } else { long nowTime = System.currentTimeMillis(); // get a non-volatile value Long currentProblemStartTimeCache = currentProblemStartTime; long expiryTime = lastSuccessTime != null ? lastSuccessTime + logWarningGraceTime.toMilliseconds() : currentProblemStartTimeCache != null ? currentProblemStartTimeCache + logWarningGraceTimeOnStartup.toMilliseconds() : nowTime + logWarningGraceTimeOnStartup.toMilliseconds(); if (!lastWasProblem) { if (expiryTime <= nowTime) { currentProblemLoggedAsWarning = true; log.warn("Read of " + getBriefDescription() + " gave " + type + ": " + val); if (log.isDebugEnabled() && val instanceof Throwable) log.debug( "Trace for " + type + " reading " + getBriefDescription() + ": " + val, (Throwable) val); } else { if (log.isDebugEnabled()) log.debug( "Read of " + getBriefDescription() + " gave " + type + " (in grace period): " + val); } lastWasProblem = true; currentProblemStartTime = nowTime; } else { if (expiryTime <= nowTime) { currentProblemLoggedAsWarning = true; log.warn( "Read of " + getBriefDescription() + " gave " + type + " (grace period expired, occurring for " + Duration.millis(nowTime - currentProblemStartTimeCache) + ", " + (config.hasExceptionHandler() ? "" : ", no exception handler set for sensor") + ")" + ": " + val); if (log.isDebugEnabled() && val instanceof Throwable) log.debug( "Trace for " + type + " reading " + getBriefDescription() + ": " + val, (Throwable) val); } else { if (log.isDebugEnabled()) log.debug( "Recurring {} reading {} in {} (still in grace period): {}", new Object[] {type, this, getBriefDescription(), val}); } } } } @SuppressWarnings("unchecked") protected void setSensor(Object v) { if (v == FeedConfig.UNCHANGED) { // nothing } else if (v == FeedConfig.REMOVE) { ((EntityInternal) entity).removeAttribute(sensor); } else if (sensor == FeedConfig.NO_SENSOR) { // nothing } else { entity.setAttribute(sensor, TypeCoercions.coerce(v, sensor.getType())); } } @Override public String toString() { return super.toString() + "[" + getDescription() + "]"; } @Override public String getDescription() { return sensor.getName() + " @ " + entity.getId() + " <- " + config; } protected String getBriefDescription() { return "" + entity + "->" + (sensor == FeedConfig.NO_SENSOR ? "(dynamic sensors)" : "" + sensor); } }
protected void logProblem(String type, Object val) { if (lastWasProblem && currentProblemLoggedAsWarning) { if (log.isTraceEnabled()) log.trace( "Recurring {} reading {} in {}: {}", new Object[] {type, this, getBriefDescription(), val}); } else { long nowTime = System.currentTimeMillis(); // get a non-volatile value Long currentProblemStartTimeCache = currentProblemStartTime; long expiryTime = lastSuccessTime != null ? lastSuccessTime + logWarningGraceTime.toMilliseconds() : currentProblemStartTimeCache != null ? currentProblemStartTimeCache + logWarningGraceTimeOnStartup.toMilliseconds() : nowTime + logWarningGraceTimeOnStartup.toMilliseconds(); if (!lastWasProblem) { if (expiryTime <= nowTime) { currentProblemLoggedAsWarning = true; log.warn("Read of " + getBriefDescription() + " gave " + type + ": " + val); if (log.isDebugEnabled() && val instanceof Throwable) log.debug( "Trace for " + type + " reading " + getBriefDescription() + ": " + val, (Throwable) val); } else { if (log.isDebugEnabled()) log.debug( "Read of " + getBriefDescription() + " gave " + type + " (in grace period): " + val); } lastWasProblem = true; currentProblemStartTime = nowTime; } else { if (expiryTime <= nowTime) { currentProblemLoggedAsWarning = true; log.warn( "Read of " + getBriefDescription() + " gave " + type + " (grace period expired, occurring for " + Duration.millis(nowTime - currentProblemStartTimeCache) + ", " + (config.hasExceptionHandler() ? "" : ", no exception handler set for sensor") + ")" + ": " + val); if (log.isDebugEnabled() && val instanceof Throwable) log.debug( "Trace for " + type + " reading " + getBriefDescription() + ": " + val, (Throwable) val); } else { if (log.isDebugEnabled()) log.debug( "Recurring {} reading {} in {} (still in grace period): {}", new Object[] {type, this, getBriefDescription(), val}); } } } }