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

Example 26 with StopWatch

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

the class ThreadLoopRunnerTest method testSetDelayTimeAndMode.

public void testSetDelayTimeAndMode() throws Exception {
    int actionWaitMillis = 1000;
    int delayMillis = 1500;
    CountDownLatch sync = new CountDownLatch(1);
    MyAction myAction = new MyAction(sync, actionWaitMillis, logger);
    ThreadLoopRunner threadLoopRunner = null;
    Exception mainBlockException = null;
    try {
        threadLoopRunner = new ThreadLoopRunner(myAction, delayMillis, TimeUnit.MILLISECONDS, tf, logger, "testDelayTimeMode");
        // setting delay mode before running loop is fine
        threadLoopRunner.setDelayMode(ScheduleDelayMode.FIXED_RATE);
        threadLoopRunner.runLoop();
        // setting delay mode while running loop must give exception
        try {
            threadLoopRunner.setDelayMode(ScheduleDelayMode.FIXED_DELAY);
            fail("Expected IllegalStateException");
        } catch (IllegalStateException ex) {
        // good
        }
        // First sleep a bit to make sure task has started
        Thread.sleep(100);
        // task runs for 1 second, so it should still be running now.
        assertTrue(threadLoopRunner.isTaskRunning());
        // changing the delay time while the task is running should stop the loop, return immediately, 
        // and later restart the loop.
        StopWatch sw = new StopWatch();
        delayMillis = 200;
        threadLoopRunner.setDelayTime(delayMillis, TimeUnit.MILLISECONDS);
        assertTrue("Calling setDelayTime should return very quickly, certainly in less than 100 ms.", sw.getLapTimeMillis() <= 100);
        // task loop should be stopped right after call to setDelayTime
        assertFalse(threadLoopRunner.isLoopRunning());
        // when task has finished (should be the case after actionWaitMillis and all the calls above),
        // the task loop should be running again, with the new delay time 200  ms.
        Thread.sleep(actionWaitMillis);
        //			assertTrue(threadLoopRunner.isLoopRunning());
        assertEquals(delayMillis, threadLoopRunner.getDelayTimeMillis());
        // verify after 10 repetitions that the new shorter delay time was actually applied
        sync = new CountDownLatch(10);
        myAction.reset(sync);
        logger.info("Now waiting for the loop to execute 10 times:");
        assertTrue("Got timeout, after just " + myAction.getCount() + " task executions", sync.await((actionWaitMillis + delayMillis) * 10 + 100, TimeUnit.MILLISECONDS));
    } catch (Exception ex1) {
        mainBlockException = ex1;
    } finally {
        if (threadLoopRunner != null) {
            try {
                assertTrue("Failed to shutdown thread loop runner in 2000 ms.", threadLoopRunner.shutdown(2000, TimeUnit.MILLISECONDS));
            } catch (Exception ex2) {
                if (mainBlockException != null) {
                    throw mainBlockException;
                } else {
                    throw ex2;
                }
            }
        }
    }
}

Example 27 with StopWatch

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

the class ThreadLoopRunnerTest method testComplexWithSuspendAndRestart.

/**
	 * Tests a well-behaved but complex usage scenario, 
	 * including calls to suspend and start again the execution loop.
	 */
public void testComplexWithSuspendAndRestart() throws Exception {
    int actionWaitMillis = 100;
    int delayMillis = 300;
    int numberOnOffCycles = 3;
    int expectedInvocationsPerCycle = 33;
    int allowedThreadJitterMillis = 200;
    CountDownLatch sync = new CountDownLatch(expectedInvocationsPerCycle);
    MyAction myAction = new MyAction(sync, actionWaitMillis, logger);
    ThreadLoopRunner threadLoopRunner = null;
    try {
        threadLoopRunner = new ThreadLoopRunner(myAction, delayMillis, TimeUnit.MILLISECONDS, tf, logger, "testComplex");
        StopWatch sw = new StopWatch();
        for (int i = 0; i < numberOnOffCycles; i++) {
            ScheduleDelayMode delayMode = i % 2 == 0 ? ScheduleDelayMode.FIXED_RATE : ScheduleDelayMode.FIXED_DELAY;
            logger.info("Will start the thread loop with delay mode " + delayMode.toString());
            threadLoopRunner.setDelayMode(delayMode);
            threadLoopRunner.runLoop();
            sw.reset();
            // wait till the last execution of the action is over
            int expectedDurationMillis = (expectedInvocationsPerCycle - 1) * delayMillis + actionWaitMillis;
            if (delayMode == ScheduleDelayMode.FIXED_DELAY) {
                expectedDurationMillis += (expectedInvocationsPerCycle - 1) * actionWaitMillis;
            }
            int timeoutMillis = expectedDurationMillis + allowedThreadJitterMillis + 1000;
            boolean awaitRet = sync.await(timeoutMillis, TimeUnit.MILLISECONDS);
            int actualDuration = (int) sw.getLapTimeMillis();
            int actualInvocations = myAction.getCount();
            assertTrue("Timed out after " + timeoutMillis + " ms", awaitRet);
            assertEquals(expectedInvocationsPerCycle, actualInvocations);
            assertTrue("Tasks were run faster (" + actualDuration + ") than expected (" + expectedDurationMillis + ")", actualDuration > expectedDurationMillis - allowedThreadJitterMillis);
            assertTrue(threadLoopRunner.isLoopRunning());
            assertFalse(threadLoopRunner.isDisabled());
            // suspend and assert that no further actions get executed 
            logger.info("Will suspend the thread loop");
            threadLoopRunner.suspendLoop();
            assertFalse(threadLoopRunner.isLoopRunning());
            assertFalse(threadLoopRunner.isDisabled());
            assertEquals(delayMode, threadLoopRunner.getDelayMode());
            Thread.sleep((actionWaitMillis + delayMillis) * 2);
            assertEquals(expectedInvocationsPerCycle, myAction.getCount());
            // run again
            sync = new CountDownLatch(expectedInvocationsPerCycle);
            myAction.reset(sync);
        }
    } finally {
        if (threadLoopRunner != null) {
            assertTrue(threadLoopRunner.shutdown(100, TimeUnit.MILLISECONDS));
        }
    }
}

Example 28 with StopWatch

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

the class AcsFileFinderTest method testClassExtractor.

public void testClassExtractor() throws Exception {
    AcsJarFileFinder jarFinder = new AcsJarFileFinder(m_dirs, m_logger);
    File[] jarFiles = jarFinder.getAllFiles();
    assertNotNull(jarFiles);
    assertTrue(jarFiles.length > 0);
    JarClassExtractor extractor = new JarClassExtractor();
    File tempDir = new File("jclass");
    if (tempDir.mkdir() == false)
        m_logger.finest("Directory " + tempDir.toString() + " might already exist.");
    long numClasses = 0;
    StopWatch sw = new StopWatch(m_logger);
    HashMap<String, String> classToJarMap = new HashMap<String, String>();
    for (int i = 0; i < jarFiles.length; i++) {
        JarFile jarFile = new JarFile(jarFiles[i]);
        JarEntry[] entries = extractor.getJavaEntries(jarFile);
        String jarName = jarFile.getName();
        numClasses += entries.length;
        for (JarEntry jarEntry : entries) {
            String className = jarEntry.getName();
            // Remove ".class" extension
            className = className.substring(0, className.length() - 6);
            String earlierJar = classToJarMap.put(className, jarName);
            if (earlierJar != null) {
            //m_logger.info(className+" "+jarName);	
            //m_logger.severe("Class "+className+" was also in "+earlierJar);
            }
        //m_logger.info(className+" "+jarName);
        }
    }
    m_logger.info("Number of classes found: " + numClasses + " in " + sw.getLapTimeMillis() + " ms.");
    File jcontClasses = new File("jcontClasses.txt");
    List<String> jarsFound = new ArrayList<String>();
    try {
        //use buffering, reading one line at a time
        //FileReader always assumes default encoding is OK!
        BufferedReader input = new BufferedReader(new FileReader(jcontClasses));
        try {
            //not declared within while loop
            String className = null;
            /*
		        * readLine is a bit quirky :
		        * it returns the content of a line MINUS the newline.
		        * it returns null only for the END of the stream.
		        * it returns an empty String if two newlines appear in a row.
		        */
            while ((className = input.readLine()) != null) {
                className = className.trim();
                String jarFound = classToJarMap.get(className);
                if (jarFound == null && !className.startsWith("java"))
                    System.out.println("Can't find jar for " + className);
                if (jarFound != null && !jarsFound.contains(jarFound)) {
                    jarsFound.add(jarFound);
                }
            }
        } finally {
            input.close();
        }
    } catch (IOException ex) {
        ex.printStackTrace();
    }
    for (String string : jarsFound) {
        System.out.println(string);
    }
}

Example 29 with StopWatch

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

the class AcsContainer method activate_component.

/////////////////////////////////////////////////////////////
// Implementation of ContainerOperations#activate_component
/////////////////////////////////////////////////////////////
/**
     * Activates a component so that it's ready to receive functional calls
     * after returning from this method. Called by the ACS Manager.
     * <p>
     * From MACI IDL:
     * <i>
     * Activate a component whose type (class) and name (instance) are given.
     * In the process of activation, component's code-base is loaded into memory if it is not there already.
     * The code-base resides in an executable file (usually a dynamic-link library or a shared library -- DLL).
     * On platforms that do not automatically load dependent executables (e.g., VxWorks),
     * the container identifies the dependencies by querying the executable and loads them automatically.
     * Once the code is loaded, it is asked to construct a servant of a given type.
     * The servant is then initialized with the Configuration Database (CDB) and Persistance Database (PDB) data.
     * The servant is attached to the component, and a reference to it is returned.
     * </i>
     * <p>
     * @param componentHandle  handle of the component that is being activated. This handle is used
     *              by the component when it will present itself to the Manager.
     *              The component is expected to remember this handle for its entire life-time.
     * @param execution_id              
     * @param compName  name of the component to instantiate (instance name, comes from CDB)
     * @param exe   component helper implementation class; must be a subclass of
     *               {@link alma.acs.container.ComponentHelper}.
     * @param type  the type of the component to instantiate (Corba IR id).
     * @return   Returns the reference to the object that has just been activated.
     *               If the component could not the activated, a nil reference is returned.
     *
     * @see si.ijs.maci.ContainerOperations#activate_component(int, String, String, String)
     */
public ComponentInfo activate_component(int componentHandle, long execution_id, String compName, String exe, String type) throws CannotActivateComponentEx {
    // reject the call if container is shutting down
    if (shuttingDown.get()) {
        String msg = "activate_component() rejected because of container shutdown.";
        m_logger.fine(msg);
        AcsJCannotActivateComponentEx ex = new AcsJCannotActivateComponentEx();
        ex.setCURL(compName);
        ex.setDetailedReason(msg);
        throw ex.toCannotActivateComponentEx();
    }
    ComponentInfo componentInfo = null;
    StopWatch activationWatch = new StopWatch(m_logger);
    // to make component activations stick out in the log list
    m_logger.finer("<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<");
    m_logger.fine("activate_component: handle=" + componentHandle + " name=" + compName + " helperClass=" + exe + " type=" + type);
    // if the container is still starting up, then hold the request until the container is ready
    boolean contInitWaitSuccess = false;
    try {
        contInitWaitSuccess = containerStartOrbThreadGate.await(30, TimeUnit.SECONDS);
    } catch (InterruptedException ex1) {
    // just leave contInitWaitSuccess == false
    }
    if (!contInitWaitSuccess) {
        String msg = "Activation of component " + compName + " timed out after 30 s waiting for the container to finish its initialization.";
        m_logger.warning(msg);
        AcsJCannotActivateComponentEx ex = new AcsJCannotActivateComponentEx();
        ex.setCURL(compName);
        ex.setDetailedReason(msg);
        throw ex.toCannotActivateComponentEx();
    }
    ComponentAdapter compAdapter = null;
    try {
        synchronized (m_activeComponentMap) {
            ComponentAdapter existingCompAdapter = getExistingComponent(componentHandle, compName, type);
            if (existingCompAdapter != null) {
                return existingCompAdapter.getComponentInfo();
            } else if (!m_activeComponentMap.reserveComponent(componentHandle)) {
                AcsJContainerEx ex = new AcsJContainerEx();
                ex.setContextInfo("Component with handle '" + componentHandle + "' is already being activated by this container. Manager should have prevented double activation.");
                throw ex;
            }
        }
        ClassLoader compCL = null;
        // the property 'acs.components.classpath.jardirs' is set by the script acsStartContainer
        // to a list of all relevant 'lib/ACScomponents/' directories
        String compJarDirs = System.getProperty(AcsComponentClassLoader.PROPERTY_JARDIRS);
        if (compJarDirs != null) {
            compCL = new AcsComponentClassLoader(Thread.currentThread().getContextClassLoader(), m_logger, compName);
        } else {
            // fallback: load component impl classes in the global class loader
            compCL = Thread.currentThread().getContextClassLoader();
        }
        // Create component helper using component classloader.
        // Note that the base class alma.acs.container.ComponentHelper will still be loaded by the container CL,
        // although the current subclassing design is a bit dirtier than it could be in the sense that a mean
        // component could deploy modified container classes (e.g. in method getInterfaceTranslator).
        // Nothing big to worry about though...
        ComponentHelper compHelper = createComponentHelper(compName, exe, compCL);
        // Creates component implementation and connects it with the Corba-generated POATie object.
        // Objects for container interception ("tight container") and for automatic xml binding class
        // de-/serialization are chained up and inserted here. End-to-end they have to translate between the
        // operations interface derived from corba IDL and the component's declared internalInterface.
        StopWatch compStopWatch = new StopWatch();
        ComponentLifecycle compImpl = compHelper.getComponentImpl();
        LOG_CompAct_Instance_OK.log(m_logger, compName, compStopWatch.getLapTimeMillis());
        //m_logger.finest(compName + " component impl created, with classloader " + compImpl.getClass().getClassLoader().getClass().getName());
        Class<? extends ACSComponentOperations> operationsIFClass = compHelper.getOperationsInterface();
        Constructor<? extends Servant> poaTieCtor = compHelper.getPOATieClass().getConstructor(new Class[] { operationsIFClass });
        Object operationsIFImpl = null;
        // translations for some methods only...
        if (operationsIFClass.isInstance(compImpl)) {
            m_logger.finer("component " + compName + " implements operations interface directly; no dynamic translator proxy used.");
            operationsIFImpl = compImpl;
        } else {
            m_logger.finer("creating dynamic proxy to map corba interface calls to component " + compName + ".");
            operationsIFImpl = compHelper.getInterfaceTranslator();
            if (!Proxy.isProxyClass(operationsIFImpl.getClass()) && !(operationsIFImpl instanceof ExternalInterfaceTranslator))
                m_logger.log(AcsLogLevel.NOTICE, "interface translator proxy for component " + compName + " isn't " + "the default one, and doesn't expose the default as one either. This may cause problem when invoking " + "xml-aware offshoot getters");
        }
        // make it a tight container (one that intercepts functional method calls)
        String[] methodsExcludedFromInvocationLogging = compHelper.getComponentMethodsExcludedFromInvocationLogging();
        Object poaDelegate = ContainerSealant.createContainerSealant(operationsIFClass, operationsIFImpl, compName, false, m_logger, compCL, methodsExcludedFromInvocationLogging);
        // construct the POATie skeleton with operationsIFImpl as the delegate object
        Servant servant = null;
        try {
            servant = poaTieCtor.newInstance(new Object[] { poaDelegate });
        } catch (Throwable thr) {
            AcsJContainerEx ex = new AcsJContainerEx(thr);
            ex.setContextInfo("failed to instantiate the servant object for component " + compName + " of type " + compImpl.getClass().getName());
            throw ex;
        }
        //
        // administrate the new component
        //
        compAdapter = new ComponentAdapter(compName, type, exe, componentHandle, m_containerName, compImpl, m_managerProxy, sharedCdbRef, compCL, m_logger, m_acsCorba);
        // to support automatic offshoot translation for xml-binded offshoots, we need to pass the dynamic adaptor
        if (!operationsIFClass.isInstance(compImpl)) {
            // if an external interface translator was given by the user, get the default interface translator
            if (operationsIFImpl instanceof ExternalInterfaceTranslator)
                operationsIFImpl = ((ExternalInterfaceTranslator) operationsIFImpl).getDefaultInterfaceTranslator();
            compAdapter.setComponentXmlTranslatorProxy(operationsIFImpl);
        }
        // for future offshoots created by this component we must pass on the no-auto-logging info
        compAdapter.setMethodsExcludedFromInvocationLogging(methodsExcludedFromInvocationLogging);
        compStopWatch.reset();
        compAdapter.activateComponent(servant);
        LOG_CompAct_Corba_OK.log(m_logger, compName, compStopWatch.getLapTimeMillis());
        // now it's time to turn off ORB logging if the new component is requesting this
        if (compHelper.requiresOrbCentralLogSuppression()) {
            ClientLogManager.getAcsLogManager().suppressCorbaRemoteLogging();
        }
        // even though the component is now an activated Corba object already,
        // it won't be called yet since the maciManager will only pass around
        // access information after we've returned from this activate_component method.
        // Therefore it's not too late to call initialize and execute, which are
        // guaranteed to be called before incoming functional calls must be expected.
        // At the moment we have to call these two methods one after the other;
        // if the Manager supports new calling semantics, we could separate the two
        // as described in ComponentLifecycle
        m_logger.fine("about to initialize component " + compName);
        compStopWatch.reset();
        compAdapter.initializeComponent();
        compAdapter.executeComponent();
        LOG_CompAct_Init_OK.log(m_logger, compName, compStopWatch.getLapTimeMillis());
        // we've deferred storing the component in the map until after it's been initialized successfully
        m_activeComponentMap.put(componentHandle, compAdapter);
        long activTime = activationWatch.getLapTimeMillis();
        m_logger.info("component " + compName + " activated and initialized in " + activTime + " ms.");
        componentInfo = compAdapter.getComponentInfo();
    } catch (Throwable thr) {
        m_logger.log(Level.SEVERE, "Failed to activate component " + compName + ", problem was: ", thr);
        if (compAdapter != null) {
            try {
                compAdapter.deactivateComponent();
            } catch (Exception ex) {
                m_logger.log(Level.FINE, ex.getMessage(), ex);
            }
        }
        m_activeComponentMap.remove(componentHandle);
        AcsJCannotActivateComponentEx ex = new AcsJCannotActivateComponentEx(thr);
        throw ex.toCannotActivateComponentEx();
    } finally {
        // to make (possibly nested) component activations stick out in the log list
        m_logger.finer(">>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>");
    }
    return componentInfo;
}

Example 30 with StopWatch

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

the class AcsContainer method createComponentHelper.

private ComponentHelper createComponentHelper(String compName, String exe, ClassLoader compCL) throws AcsJContainerEx {
    m_logger.finer("creating component helper instance of type '" + exe + "' using classloader " + compCL.getClass().getName());
    StopWatch sw = new StopWatch();
    Class<? extends ComponentHelper> compHelperClass = null;
    try {
        compHelperClass = (Class.forName(exe, true, compCL).asSubclass(ComponentHelper.class));
    } catch (ClassNotFoundException ex) {
        AcsJContainerEx ex2 = new AcsJContainerEx(ex);
        ex2.setContextInfo("component helper class '" + exe + "' not found.");
        throw ex2;
    } catch (ClassCastException ex) {
        AcsJContainerEx ex2 = new AcsJContainerEx();
        ex2.setContextInfo("component helper class '" + exe + "' does not inherit from required base class " + ComponentHelper.class.getName());
        throw ex2;
    }
    // We really only measure the time to load the component helper class, 
    // but since we expect the comp impl class to be in the same jar file, our class loader should 
    // then learn about it and be very fast loading it later.
    LOG_CompAct_Loading_OK.log(m_logger, compName, sw.getLapTimeMillis());
    Constructor<? extends ComponentHelper> helperCtor = null;
    ComponentHelper compHelper = null;
    try {
        helperCtor = compHelperClass.getConstructor(new Class[] { Logger.class });
    } catch (NoSuchMethodException ex) {
        String msg = "component helper class '" + exe + "' has no constructor " + " that takes a java.util.Logger";
        m_logger.fine(msg);
        AcsJContainerEx ex2 = new AcsJContainerEx(ex);
        ex2.setContextInfo(msg);
        throw ex2;
    }
    try {
        compHelper = helperCtor.newInstance(new Object[] { m_logger });
    } catch (Throwable thr) {
        AcsJContainerEx ex = new AcsJContainerEx(thr);
        ex.setContextInfo("component helper class '" + exe + "' could not be instantiated");
        throw ex;
    }
    // here we don't log LOG_CompAct_Instance_OK because instantiating the component itself is expected to take longer
    // than instantiating the comp helper here. 
    // To be more accurate, we'd have to add up those times, which would be rather ugly in the current code.
    compHelper.setComponentInstanceName(compName);
    return compHelper;
}