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

Example 36 with StopWatch

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

the class ComponentRefTracker method runLoop.

private void runLoop() throws IOException, InterruptedException {
    long nextCallTime = -1;
    if (inputReader != null) {
        m_logger.info("Press ENTER to call " + targetCompUrl);
    }
    while (shutdownSync == null) {
        // Check if we should simply wait for user input or more time to pass
        if ((inputReader != null && !inputReader.ready()) || System.currentTimeMillis() < nextCallTime) {
            // sleep short time only, to be responsive to shutdown
            Thread.sleep(100);
            continue;
        }
        if (inputReader != null) {
            // We are in interactive mode.
            // There is user input, thus we can dare to call the otherwise non-interruptable blocking readLine() method.
            inputReader.readLine();
        }
        StopWatch sw = new StopWatch();
        try {
            if (checkExists && targetComp._non_existent()) {
                // Not sure if we gain anything from calling _non_existent.
                // It may only return true if our proxy object has been destroyed.
                // In case of target container ORB problems, it will throw an exception, just like the name() call does.
                m_logger.info("Component '" + targetCompUrl + "' does not exist (see Corba spec 4.3.5.1). Call took " + sw.getLapTimeMillis() + " ms.");
            } else {
                String currentName = targetComp.name();
                String msg = "Call to " + targetCompUrl + "#name() returned fine";
                if (!targetCompUrl.equals(currentName)) {
                    msg += " but with unexpected name '" + currentName;
                }
                m_logger.info(msg + ". Call took " + sw.getLapTimeMillis() + " ms.");
            }
        } catch (Throwable thr) {
            m_logger.info("Call to component '" + targetCompUrl + "' failed with " + thr.getClass().getName() + ", after " + sw.getLapTimeMillis() + " ms.");
        }
        if (inputReader == null) {
            nextCallTime = System.currentTimeMillis() + pingDelaySec * 1000;
        }
    }
}

Example 37 with StopWatch

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

the class AcsCorba method deactivateComponentPOAManager.

/**
	 * Deactivates a component's POA manager. 
	 * The effect is that no further calls will reach the component.
	 * This method returns immediately if the POA manager is already inactive.
	 * Otherwise it will only return when the active requests are done.
	 * <p>
	 * Note for JacORB (1.4 as well as 2.2.4): there seems to be a problem in 
	 * <code>org.jacorb.poa.RequestController#waitForCompletion</code> with local calls (e.g. collocated component). 
	 * Instead of duly waiting for completion, that method returns immediately when such calls are still executing. 
	 * Even worse, <code>RequestController#activeRequestTable</code> seems to never get touched in case of local calls.
	 * There is a currently commented out JUnit test that verifies this problem.
	 * <p>
	 * The purpose of this method is to allow the container to "drain" a component of requests,
	 * so that <code>cleanUp</code> can be called while no functional calls are running or can come in.
	 * An alternative to using the component POA manager could be to destroy the component POA before
	 * calling <code>cleanUp</code>. This has the disadvantage of also destroying the offshoot child POA,
	 * which is needed to properly clean up callback connections.
	 * <p>
	 * Note that {@link POAManager#deactivate(boolean, boolean)} is called in a separate thread,
	 * so that this method itself may well be called from an ORB thread.
	 * This method uses <code>etherealize_objects=false</code> and <code>wait_for_completion=true</code>.
	 * 
	 * @param compPOA the component POA
	 * @param compName component instance name
	 * @param timeoutMillis timeout in milliseconds after which this call returns even if the POA manager is not inactive yet.
	 * @return true if the POA manager is inactive.
	 */
public boolean deactivateComponentPOAManager(POA compPOA, final String compName, int timeoutMillis) {
    final POAManager compPOAManager = compPOA.the_POAManager();
    if (compPOAManager.get_state() == State.INACTIVE) {
        return true;
    }
    final CountDownLatch deactivateSyncer = new CountDownLatch(1);
    // todo: use thread pool instead of always creating a thread for this purpose
    Thread discardRequestsThread = new Thread(new Runnable() {

        public void run() {
            try {
                // note that deactivate(wait_for_completion=true) must not be called from an ORB thread, 
                // thus we use a separate thread here. This is quite annoying because 
                // at least in JacORB's implementation, another new thread is created inside deactivate
                compPOAManager.deactivate(false, true);
                //					compPOAManager.discard_requests(true);
                deactivateSyncer.countDown();
            } catch (AdapterInactive e) {
                m_logger.log(Level.INFO, "Failed to finish and reject requests for component " + compName, e);
            }
        }
    });
    discardRequestsThread.setDaemon(true);
    discardRequestsThread.setName("deactivatePOAManager_" + compName);
    StopWatch stopWatch = null;
    if (m_logger.isLoggable(Level.FINEST)) {
        stopWatch = new StopWatch();
    }
    discardRequestsThread.start();
    boolean isInactive = false;
    try {
        isInactive = deactivateSyncer.await(timeoutMillis, TimeUnit.MILLISECONDS);
    } catch (InterruptedException e) {
    // isInactive == false
    } finally {
        if (m_logger.isLoggable(Level.FINEST)) {
            long deactivationTime = stopWatch.getLapTimeMillis();
            String msg = "POA manager deactivation for component '" + compName + "' was " + (isInactive ? "" : "*not* ") + "successful and took " + deactivationTime + " ms. " + "The component can" + (isInactive ? "not" : "") + " receive further calls over CORBA.";
            m_logger.finest(msg);
        }
    }
    return isInactive;
}

Example 38 with StopWatch

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

the class Helper method createNotifyChannel_internal.

/**
	 * Broken out from {@link #createNotificationChannel(String, String, String)}
	 * to give tests better control about the timing when this call to the event factory is made.
	 * @throws NameAlreadyUsed if the call to NotifyFactory#create_named_channel fails with this exception.
	 * @throws AcsJCORBAProblemEx if the TAO extension throws a NameMapError or if the QoS attributes cause a UnsupportedAdmin.
	 */
protected EventChannel createNotifyChannel_internal(Property[] initial_qos, Property[] initial_admin, IntHolder channelIdHolder) throws NameAlreadyUsed, UnsupportedQoS, AcsJNarrowFailedEx, AcsJCORBAProblemEx {
    EventChannel ret = null;
    StopWatch stopwatch = new StopWatch();
    try {
        // The TAO extension of the notify factory that we use declares only the plain EventChannel type, 
        // even though it creates the TAO-extension subtype.
        org.omg.CosNotifyChannelAdmin.EventChannel eventChannelBaseType = notifyFactory.create_named_channel(initial_qos, initial_admin, channelIdHolder, channelName);
        LOG_NC_ChannelCreatedRaw_OK.log(m_logger, channelName, channelIdHolder.value, stopwatch.getLapTimeMillis());
        // re-create the client side corba stub, to get the extension subtype
        ret = gov.sandia.NotifyMonitoringExt.EventChannelHelper.narrow(eventChannelBaseType);
    } catch (BAD_PARAM ex) {
        LOG_NC_TaoExtensionsSubtypeMissing.log(m_logger, channelName, EventChannel.class.getName(), org.omg.CosNotifyChannelAdmin.EventChannelHelper.id());
        AcsJNarrowFailedEx ex2 = new AcsJNarrowFailedEx(ex);
        ex2.setNarrowType(EventChannelHelper.id());
        throw ex2;
    } catch (NameMapError ex) {
        String msg = "Got a TAO extension-specific NameMapError exception that means the TAO NC extension is not usable. Bailing out since we need the extension.";
        m_logger.log(AcsLogLevel.ERROR, msg, ex);
        AcsJCORBAProblemEx ex2 = new AcsJCORBAProblemEx(ex);
        ex2.setInfo(msg);
        throw ex2;
    } catch (UnsupportedAdmin ex) {
        AcsJCORBAProblemEx ex2 = new AcsJCORBAProblemEx(ex);
        ex2.setInfo(createUnsupportedAdminLogMessage(ex));
        throw ex2;
    }
    return ret;
}

Example 39 with StopWatch

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

the class IOHelper method loadLogs.

/**
	 * Load the logs from the given <code>BufferedReader</code>.
	 * <P>
	 * The logs are sent to the <code>ACSRemoteLogListener</code> and /or
	 * to the <code>ACSRemoteRawLogListener</code>.
	 *  
	 * @param reader The reader to read logs from
	 * @param logListener The callback for each new log read from the IO
	 * @param rawLogListener The callback for each new XML log read from the IO
	 * @param errorListener The listener for errors
	 * @param progressListener The listener to be notified about the bytes read
	 * 
	 * @throws IOException In case of an IO error while reading the file
	 */
public synchronized void loadLogs(BufferedReader reader, ACSRemoteLogListener logListener, ACSRemoteRawLogListener rawLogListener, ACSRemoteErrorListener errorListener, IOPorgressListener progressListener) throws IOException {
    if (reader == null || errorListener == null) {
        throw new IllegalArgumentException("Parameters can't be null");
    }
    if (logListener == null && rawLogListener == null) {
        throw new IllegalArgumentException("No log listeners defined");
    }
    if (progressListener == null) {
        throw new IllegalArgumentException("The progress listener can't be null");
    }
    stopped = false;
    // The "clever" buffer
    LogStringBuffer buffer = new LogStringBuffer();
    // Read one char per iteration
    int chRead;
    // Count the bytes read
    int bytesRead = 0;
    int logRecordsRead = 0;
    // Here the buffer writes the XML of each log
    StringBuilder xmlStr = new StringBuilder();
    /**
		 * The size of the buffer
		 */
    final int size = 16384;
    /** 
		 * The buffer of data read from the file
		 */
    char[] buf = new char[size];
    /**
		 * The cursor to scan the buffer (circular)
		 */
    int actualPos = -1;
    /**
		 * When it is 0, then we have to read another block from the file
		 */
    int bytesInBuffer = 0;
    StopWatch stopWatch = new StopWatch();
    // This thread is very CPU demanding so we want to give other
    // threads a chance to run too...
    int yelder = 0;
    while (true && !stopped) {
        // Read a block from the file if the buffer is empty
        if (bytesInBuffer == 0) {
            bytesInBuffer = reader.read(buf, 0, size);
        }
        if (bytesInBuffer <= 0) {
            // EOF
            break;
        }
        bytesInBuffer--;
        actualPos = (actualPos + 1) % size;
        chRead = buf[actualPos];
        bytesRead++;
        buffer.append((char) chRead, xmlStr);
        if (xmlStr.length() > 0) {
            // A new log has been found
            injectLog(xmlStr, logListener, rawLogListener, errorListener);
            logRecordsRead++;
            xmlStr.delete(0, xmlStr.length());
            progressListener.bytesRead(bytesRead);
            if (logRecordsRead % 25 == 0) {
                progressListener.logsRead(logRecordsRead);
            }
        }
        yelder = (yelder++) % 5000;
        if (yelder == 0) {
            Thread.yield();
        }
    }
    System.out.println("XML log record import finished with " + logRecordsRead + " records in " + stopWatch.getLapTimeMillis() / 1000 + " seconds.");
}

Example 40 with StopWatch

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

the class BlobberWorker method run.

/**
	 * This method will be called at fixed intervals. It gathers the data from all registered collectors and stores it
	 * in the database, using the layer from module TMCBD/DAO.
	 * 
	 * @see java.lang.Runnable#run()
	 */
@Override
public void run() {
    cycleCount.incrementAndGet();
    myLogger.fine("Running BlobberWorker cycle " + cycleCount);
    int collectorCount = 0;
    int insertCount = 0;
    StopWatch stopWatchAllCollectors = new StopWatch(myLogger);
    // Checking memory requires a GC run (and no other components running in the same container)
    // to give reasonable results. Running GC from inside the program we don't want to do as default,
    // thus the use of the cheating property.
    long usedMemKBBeforeCycle = -1;
    if (Boolean.getBoolean(BLOBBER_CHECK_JVM_MEMORY_PROPERTYNAME)) {
        System.gc();
        Runtime rt = Runtime.getRuntime();
        usedMemKBBeforeCycle = (rt.totalMemory() - rt.freeMemory()) / 1024;
        myLogger.fine("Used JVM memory in kB after GC before blobber cycle: " + usedMemKBBeforeCycle);
    }
    // loop over all collectors. Note that collectors can be added and removed during this loop,
    // so that the initial list size does not necessarily show the number of executed collectors.
    CollectorData collectorData = null;
    myCollectorList.resetIterator();
    while (myCollectorList.hasNext()) {
        try {
            collectorData = myCollectorList.next();
            // has this thread been requested to terminate?
            if (shouldTerminate) {
                myLogger.info("Loop over collectors terminated prematurely, skipping '" + collectorData.getCollectorId() + "' and subsequent collectors.");
                break;
            }
            collectorCount++;
            StopWatch stopWatchCurrentCollector = new StopWatch(myLogger);
            // Get the corba ref for the current collector
            MonitorCollectorOperations collector = getMonitorCollector(collectorData.getCollectorId());
            // The data retrieval, processing, and storage happens here
            insertCount += harvestCollector(collectorData, collector);
            stopWatchCurrentCollector.logLapTime("process monitoring data from collector " + collectorData.getCollectorId());
        } catch (Exception e) {
            myLogger.log(Level.WARNING, "Exception caught while processing monitor collector " + collectorData.getCollectorId() + "; the data cache for this collector will be cleared, the data is LOST FOREVER", e);
        // @TODO Shouldn't we raise an alarm also here, now that we do when blobber comp fails to initialize?
        // Then it would need to be cleared once (the same collector's??) data is processed ok in the next round.
        }
    }
    if (Boolean.getBoolean(BLOBBER_CHECK_JVM_MEMORY_PROPERTYNAME)) {
        System.gc();
        Runtime rt = Runtime.getRuntime();
        long usedMemKBAfterCycle = (rt.totalMemory() - rt.freeMemory()) / 1024;
        myLogger.fine("Used JVM memory in kB after GC after blobber cycle: " + usedMemKBAfterCycle);
    }
    long totalTimeMillis = stopWatchAllCollectors.getLapTimeMillis();
    if (totalTimeMillis < collectIntervalSec * 1000) {
        // the good case: all collectors were processed within the foreseen time window
        String msg = "Processed monitoring data from " + collectorCount + " collector(s) in " + totalTimeMillis + " ms (within the time limit).";
        myLogger.fine(msg);
        if (isProfilingEnabled) {
            debugDataSender.sendUDPPacket(msg, cycleCount.longValue());
            debugDataSender.sendUDPPacket("Total inserts for cycle " + cycleCount + " were " + insertCount, cycleCount.longValue());
        }
    } else {
        // the bad case: this run took too long.
        String msg = "Processed monitoring data from " + collectorCount + " collector(s) in " + totalTimeMillis + " ms (exceeding the time limit of " + collectIntervalSec + " s).";
        myLogger.warning(msg);
        if (isProfilingEnabled) {
            debugDataSender.sendUDPPacket(msg, cycleCount.longValue());
            debugDataSender.sendUDPPacket("Total inserts for cycle " + cycleCount + " were " + insertCount, cycleCount.longValue());
        }
    }
}