Examples with StopWatch alma.acs.util.StopWatch used on opensource projects

Example 21 with StopWatch

use of alma.acs.util.StopWatch in project ACS by ACS-Community.

the class InMemoryNcTest method testConcurrentUse.

/**
	 * Heavy-duty test to check for concurrency problems
	 * and to do basic verification of throughput performance (which is limited by having a single receiver).
	 * <p>
	 * We want to test also the asynchronous event processing in AcsEventSubscriberImplBase, 
	 * but then must throttle the publishers so that the subscribers don't lose data.
	 * Still we want the publishers to fire fast enough so that the subscribers get stressed at times.
	 * This is achieved by letting the publishers fire batches of events at maximum speed,
	 * but then wait for the entire batch to be received by the registered receiver class.
	 * These pulses of events are calculated to at most fill up the subscriber queue completely,
	 * which means that we may get warnings about slow receivers ("More events came in from the NC than the receiver processed"), 
	 * but still no data should be lost ("numEventsDiscarded=0").
	 */
@Test
public void testConcurrentUse() throws Exception {
    InMemoryNcFake nc = new InMemoryNcFake(services, "myTestChannel");
    final int numEventsPerPublisher = 2000;
    final int numPublishers = 5;
    final int numEventsPublishedTotal = numEventsPerPublisher * numPublishers;
    final int numActiveSubscribers = 5;
    final int numInactiveSubscribers = 2;
    final int numEventsToReceiveTotal = numEventsPublishedTotal * numActiveSubscribers;
    final int eventBatchSize = Math.min(numEventsPerPublisher, AcsEventSubscriberImplBase.EVENT_QUEUE_CAPACITY / numPublishers);
    assertThat("Current choice of test parameters leads to illegal batch size.", eventBatchSize, greaterThanOrEqualTo(1));
    final int numEventsToReceivePerBatch = eventBatchSize * numPublishers * numActiveSubscribers;
    logger.info("Will use " + numPublishers + " publishers to each publish " + numEventsPerPublisher + " events (in batches of " + eventBatchSize + " each synchronized with the receivers), and " + numActiveSubscribers + " subscribers for these events. In addition we have " + numInactiveSubscribers + " subscribers that should not receive these events.");
    StopWatch sw = new StopWatch(logger);
    // set up publishers (unlike above we do it before the subscribers, just to make sure that works as well)
    List<InMemoryPublisher<TestEventType1>> publishers = new ArrayList<InMemoryPublisher<TestEventType1>>(numPublishers);
    for (int i = 1; i <= numPublishers; i++) {
        AcsEventPublisher<TestEventType1> pub = nc.createPublisher("myTestPublisher" + i, TestEventType1.class);
        publishers.add((InMemoryPublisher) pub);
    }
    sw.logLapTime("create " + numPublishers + " publishers");
    // set up subscribers
    final SyncingEventCollector eventCollector = new SyncingEventCollector(numPublishers, numEventsToReceivePerBatch, numEventsToReceiveTotal);
    TestEventReceiver1 sharedReceiver = new TestEventReceiver1(eventCollector);
    List<AcsEventSubscriber<?>> subscribers = new ArrayList<AcsEventSubscriber<?>>(numActiveSubscribers);
    for (int i = 1; i <= numActiveSubscribers; i++) {
        AcsEventSubscriber<TestEventType1> sub = nc.createSubscriber("myTestSubscriber" + i, TestEventType1.class);
        subscribers.add(sub);
        sub.addSubscription(sharedReceiver);
        sub.startReceivingEvents();
    }
    for (int i = 1; i <= numInactiveSubscribers; i++) {
        if (i % 2 == 0) {
            AcsEventSubscriber<TestEventType1> sub = nc.createSubscriber("myInactiveTestSubscriber" + i, TestEventType1.class);
            subscribers.add(sub);
            sub.addSubscription(sharedReceiver);
        // do not call sub.startReceivingEvents() for this inactive subscriber
        } else {
            AcsEventSubscriber<TestEventType2> sub = nc.createSubscriber("myTestSubscriber" + i, TestEventType2.class);
            subscribers.add(sub);
            sub.startReceivingEvents();
        }
    }
    sw.logLapTime("create " + (numActiveSubscribers + numInactiveSubscribers) + " subscribers");
    // Publish and receive "event1" as specified above
    final TestEventType1 event1 = new TestEventType1();
    final List<Throwable> asyncThrowables = Collections.synchronizedList(new ArrayList<Throwable>());
    final CountDownLatch synchOnPublishers = new CountDownLatch(numPublishers);
    class PublisherRunnable implements Runnable {

        private final InMemoryPublisher<TestEventType1> publisher;

        PublisherRunnable(InMemoryPublisher<TestEventType1> publisher) {
            this.publisher = publisher;
        }

        @Override
        public void run() {
            for (int i = 1; i <= numEventsPerPublisher; i++) {
                try {
                    publisher.publishEvent(event1);
                    if (i % eventBatchSize == 0) {
                        awaitEventReception();
                    }
                } catch (Exception ex) {
                    asyncThrowables.add(ex);
                }
            }
            // test getEventCount()
            if (publisher.getEventCount() != numEventsPerPublisher) {
                asyncThrowables.add(new Exception("Published only " + publisher.getEventCount() + " events when " + numEventsPerPublisher + " were expected."));
            }
            try {
                publisher.disconnect();
            } catch (AcsJIllegalStateEventEx ex) {
                asyncThrowables.add(ex);
            }
            // the last batch may be smaller than eventBatchSize, so that we need to sync on their reception with this extra call
            awaitEventReception();
            synchOnPublishers.countDown();
        }

        private void awaitEventReception() {
            try {
                //					StopWatch swWait = new StopWatch(logger);
                eventCollector.awaitEventBatchReception();
            //					logger.fine("Publisher in thread " + Thread.currentThread().getName() + " returned from awaitEventBatchReception() in " + swWait.getLapTimeMillis() + " ms.");
            } catch (Exception ex) {
                asyncThrowables.add(ex);
            }
        }
    }
    // let each publisher fire its events from a separate thread
    for (InMemoryPublisher<TestEventType1> publisher : publishers) {
        services.getThreadFactory().newThread(new PublisherRunnable(publisher)).start();
    }
    // wait for publishers to fire all events (which includes already their waiting for event reception)
    assertThat(synchOnPublishers.await(1, TimeUnit.MINUTES), is(true));
    // verify results
    assertThat(asyncThrowables, is(empty()));
    assertThat(eventCollector.getNumEventsReceivedTotal(), equalTo((long) numEventsToReceiveTotal));
    sw.logLapTime("publish " + numEventsPublishedTotal + " and receive " + numEventsToReceiveTotal + " events");
}

Example 22 with StopWatch

use of alma.acs.util.StopWatch in project ACS by ACS-Community.

the class AcsEventSubscriberImplBase method processEvent.

/**
	 * This method should be called from the subclass-specific method that receives the event,
	 * for example <code>push_structured_event</code> in case of Corba NC,
	 * or preferably via {@link #processEventAsync(Object, EventDescription)}.
	 * <p>
	 * No exception is allowed to be thrown by this method, even if the receiver implementation throws a RuntimeExecption
	 * @param eventData (defined as <code>Object</code> instead of <code>T</code> to include data for generic subscription).
	 * @param eventDesc
	 */
protected void processEvent(Object eventData, EventDescription eventDesc) {
    Class<?> incomingEventType = eventData.getClass();
    String eventName = incomingEventType.getName();
    // figure out how much time this event has to be processed (according to configuration)
    double maxProcessTimeSeconds = getMaxProcessTimeSeconds(eventName);
    StopWatch profiler = new StopWatch();
    // we give preference to a receiver that has registered for this event type T or a subtype
    if (eventType.isAssignableFrom(incomingEventType) && receivers.containsKey(incomingEventType)) {
        @SuppressWarnings("unchecked") T typedEventData = (T) eventData;
        Callback<? extends T> receiver = receivers.get(incomingEventType);
        profiler.reset();
        try {
            _process(receiver, typedEventData, eventDesc);
        } catch (Throwable thr) {
            logEventReceiveHandlerException(eventName, receiver.getClass().getName(), thr);
        }
        double usedSecondsToProcess = (profiler.getLapTimeMillis() / 1000.0);
        // warn the end-user if the receiver is taking too long, using a repeat guard
        if (usedSecondsToProcess > maxProcessTimeSeconds && processTimeLogRepeatGuard.checkAndIncrement(eventName)) {
            logEventProcessingTimeExceeded(eventName, processTimeLogRepeatGuard.counterAtLastExecution(eventName));
        }
    } else // fallback to generic receive method
    if (genericReceiver != null) {
        profiler.reset();
        genericReceiver.receiveGeneric(eventData, eventDesc);
        double usedSecondsToProcess = (profiler.getLapTimeMillis() / 1000.0);
        // warn the end-user if the receiver is taking too long 
        if (usedSecondsToProcess > maxProcessTimeSeconds && processTimeLogRepeatGuard.checkAndIncrement(eventName)) {
            logEventProcessingTimeExceeded(eventName, processTimeLogRepeatGuard.counterAtLastExecution(eventName));
        }
    } else // No receiver found.
    // This may be OK or not, depending on whether the subclass sets up filtering in the underlying notification framework
    // that ensures that only subscribed event types reach the subscriber. Subclass should decide if and how to report this.
    {
        logNoEventReceiver(eventName);
    }
}

Example 23 with StopWatch

use of alma.acs.util.StopWatch in project ACS by ACS-Community.

the class PopulateEventList method getThreadForEventList.

Thread getThreadForEventList() {
    Runnable eventListRunnable = new Runnable() {

        public Runnable r = new Runnable() {

            private long totalNumberDrained;

            public void run() {
                //final Display display = viewer.getControl().getDisplay();
                if (!display.isDisposed()) {
                    ArrayList c = new ArrayList(QUEUE_DRAIN_LIMIT);
                    int numberDrained = queue.drainTo(c, QUEUE_DRAIN_LIMIT);
                    if (numberDrained == 0)
                        return;
                    totalNumberDrained += numberDrained;
                    synchronized (this) {
                        // TODO -- figure out why this doesn't work; need same lock on display everywhere?
                        if (!display.isDisposed())
                            viewer.add(c.toArray());
                    }
                    if (cycles++ % CHECK_MEMORY_FREQUENCY == 0) {
                        StopWatch sw = new StopWatch(logger);
                        freeMemoryIfNecessary();
                        sw.logLapTime("Check free memory");
                        logger.fine("Total rows processed so far: " + totalNumberDrained);
                        String rateStr;
                        if (threadName.equals("NC Events"))
                            rateStr = String.format("Average event rate from all subscribed channels: %.2f events/s", EventData.getAverageRate());
                        else
                            rateStr = String.format("Average archiving rate: %.2f monitor points/s", ArchiveEventData.getAverageRate());
                        statusLineWriter.setMessage(rateStr);
                    }
                }
            }
        };

        public void run() {
            while (!Thread.currentThread().isInterrupted()) {
                if (display.isDisposed())
                    return;
                try {
                    display.syncExec(r);
                    //display.asyncExec(r);
                    Thread.sleep(1000);
                //					System.out.println("Event list iteration " + ++i);
                //					System.out.println("Queue has "
                //							+ Application.equeue.remainingCapacity()
                //							+ " slots left.");
                } catch (InterruptedException e) {
                    // TODO: Change thread model, as this happens at shutdown
                    System.out.println("Event monitoring was interrupted!");
                    break;
                // Application.setMonitoring(false);
                // startMonitoringAction.setEnabled(true);
                } catch (SWTException e) {
                    // eat it
                    break;
                }
            }
        // Application.setMonitoring(false);
        // startMonitoringAction.setEnabled(true);
        }
    };
    final Thread th = new Thread(eventListRunnable, threadName);
    return th;
}

Example 24 with StopWatch

use of alma.acs.util.StopWatch in project ACS by ACS-Community.

the class CounterConsumerImpl method cleanUp.

@Override
public void cleanUp() throws AcsJComponentCleanUpEx {
    if (subscriber != null) {
        m_logger.info("cleanUp() called, disconnecting from channel " + alma.COUNTER.CHANNELNAME_COUNTER.value);
        StopWatch sw = new StopWatch();
        try {
            subscriber.disconnect();
            subscriber = null;
        } catch (Exception ex) {
            // could be IllegalStateException if the consumer is already disconnected.
            throw new AcsJComponentCleanUpEx(ex);
        }
        long disconnectTimeMillis = sw.getLapTimeMillis();
        if (disconnectTimeMillis > 600) {
            m_logger.info("Suspiciously slow NC disconnect in " + disconnectTimeMillis + " ms.");
        }
    } else {
        m_logger.info("cleanUp() called..., nothing to clean up.");
    }
}

Example 25 with StopWatch

use of alma.acs.util.StopWatch in project ACS by ACS-Community.

the class ThreadBurstExecutorServiceTest method testParallelExecutor.

public void testParallelExecutor() throws Exception {
    ThreadFactory tf = new DaemonThreadFactory("ThreadBurstExecutorServiceTest");
    ThreadBurstExecutorService exec = new ThreadBurstExecutorService(tf);
    int num = 333;
    long threadSleepMillis = 1000;
    // Set up <num> threads to be executed at once
    StopWatch sw = new StopWatch();
    CountDownLatch sharedExecutionVerifier = new CountDownLatch(num);
    for (int i = 0; i < num; i++) {
        Callable<Void> task = new TestCallable(i, sharedExecutionVerifier, threadSleepMillis);
        exec.submit(task, threadSleepMillis * 2, TimeUnit.MILLISECONDS);
    }
    assertEquals(num, sharedExecutionVerifier.getCount());
    System.out.println("All " + num + " threads are now running. It took " + sw.getLapTimeMillis() + " ms to set them up.");
    // execute these threads and wait for tasks to finish
    assertTrue(exec.executeAllAndWait(threadSleepMillis + 1000, TimeUnit.MILLISECONDS));
    // the call() methods of our TestCallable should have decremented the sharedExecutionVerifier counter
    assertEquals(0, sharedExecutionVerifier.getCount());
    // try to call it again
    try {
        exec.executeAllAndWait(threadSleepMillis + 1000, TimeUnit.MILLISECONDS);
        fail("Expected IllegalStateException when calling executeAllAndWait a second time.");
    } catch (IllegalStateException ex) {
    // expected
    }
    // try to submit another task
    try {
        Runnable task2 = new Runnable() {

            public void run() {
            }
        };
        exec.submit(task2, threadSleepMillis + 1000, TimeUnit.MILLISECONDS);
        fail("Expected IllegalStateException when calling submit after executeAllAndWait.");
    } catch (IllegalStateException ex) {
    // expected
    }
}