Examples with AcsLogLevelDefinition alma.acs.logging.level.AcsLogLevelDefinition used on opensource projects

Example 11 with AcsLogLevelDefinition

use of alma.acs.logging.level.AcsLogLevelDefinition in project ACS by ACS-Community.

the class ClientWithLogReceiverTest method testLogQueueNoDelay.

/**
     * Logs a single record and waits for it to come back from the Log service 
     * and to pass the queue (which is set to zero delay).
     * Then the record is verified, and the same test is repeated a couple of times with different log records. 
     * @throws Exception
     */
public void testLogQueueNoDelay() throws Exception {
    LogConfig logConfig = ClientLogManager.getAcsLogManager().getLogConfig();
    assertEquals("For this test, even low-level logs must be sent off remotely.", AcsLogLevelDefinition.TRACE, logConfig.getDefaultMinLogLevel());
    logReceiver.setDelayMillis(0);
    BlockingQueue<DelayedLogEntry> queue = logReceiver.getLogQueue();
    // the set of log levels to be randomly selected for the test logs 
    AcsLogLevelDefinition[] coreLevels = new AcsLogLevelDefinition[] { AcsLogLevelDefinition.TRACE, AcsLogLevelDefinition.DEBUG, AcsLogLevelDefinition.INFO, AcsLogLevelDefinition.WARNING, AcsLogLevelDefinition.EMERGENCY };
    int numberOfTestLogs = 10;
    Random random = new Random(System.currentTimeMillis());
    // loop for sending several test logs
    for (int i = 0; i < numberOfTestLogs; i++) {
        AcsLogLevelDefinition coreLevel = coreLevels[random.nextInt(coreLevels.length)];
        // TODO: using getLowestMatchingJdkLevel here may be temporary, see COMP-3925. 
        Level jdkLevel = AcsLogLevel.getLowestMatchingJdkLevel(coreLevel);
        // Log the test record
        String logMessage = "This is log number " + i;
        m_logger.log(jdkLevel, logMessage);
        // Wait for the test record to come back from the Log service.
        // In spite of zero queue sorting delay, we need a long timeout 
        // to compensate for travel delays to and from the Log service.
        // should be much less, but currently we have problems there.
        int delayLogServiceSec = 20;
        int timeoutSec = logConfig.getFlushPeriodSeconds() + delayLogServiceSec;
        long timeoutSysMillis = System.currentTimeMillis() + timeoutSec * 1000;
        while (true) {
            // System.currentTimeMillis() < timeoutSysMillis
            // wait on the queue for a log record to arrive
            DelayedLogEntry delayedLogEntry = queue.poll(timeoutSysMillis - System.currentTimeMillis(), TimeUnit.MILLISECONDS);
            if (delayedLogEntry != null) {
                // got something, must check if it was the record we sent
                if (delayedLogEntry.isQueuePoison()) {
                    fail("Unexpected end of log queue.");
                }
                LogReceiver.ReceivedLogRecord logRecord = delayedLogEntry.getLogRecord();
                String sourceObjectName = logRecord.getSourceObject();
                if (sourceObjectName != null && sourceObjectName.equals("ClientWithLogReceiverTest#testLogQueueNoDelay") && !logRecord.getMessage().startsWith("------------ setUp") && !logRecord.getMessage().startsWith("Alarm system type:")) {
                    // it's a log record sent from this process 
                    assertEquals("Log message text must match the test log record", logMessage, logRecord.getMessage());
                    assertEquals("Log level must match the test log record", coreLevel, logRecord.getLevel().getAcsCoreLevel());
                    System.out.println("Received back log record #" + i);
                    // and continue outer loop with next log record
                    break;
                } else {
                    // was some other stray log, perhaps from a previously running ACS component, or the pinging jmanager
                    // we stay in the while loop and wait again for another record to be delivered by the queue
                    System.out.println(IsoDateFormat.formatCurrentDate() + ": Ignoring received log " + IsoDateFormat.formatDate(logRecord.getTimestamp()) + " [" + sourceObjectName + "]");
                }
            } else {
                fail("Did not receive the expected log record #" + i + " within " + timeoutSec + " seconds.");
            }
        }
    }
    logReceiver.stop();
}

Example 12 with AcsLogLevelDefinition

use of alma.acs.logging.level.AcsLogLevelDefinition in project ACS by ACS-Community.

the class PubSubExecutor method execute.

/**
	 * Run the specified pub/sub container and components.
	 * If this method gets called directly (and not by {@link #execute(PubSubScenario)}, 
	 * the executionTime parameter can overwrite the timeout setting from the XML, or can 
	 * set a timeout complementary to a finite <code>PubSubSpecCommonT#numberOfEvents</code>.
	 */
public void execute(PubSubScenario scenario, long executionTimeMax, TimeUnit executionTimeMaxUnit) throws Throwable {
    PubSubInfrastructureSpec pubSubSpec = scenario.getSpec();
    m_logger.info("Will execute test with description:\n" + pubSubSpec.getTestDescription());
    SimpleLoggingSpecT loggingSpec = (pubSubSpec.getLogging() != null ? pubSubSpec.getLogging() : defaultLoggingSpec);
    AcsLogLevelDefinition levelDefaultLocal = AcsLogLevelDefinition.fromInteger(loggingSpec.getDefaultLevelMinLocal());
    AcsLogLevelDefinition levelDefault = AcsLogLevelDefinition.fromInteger(loggingSpec.getDefaultLevelMin());
    AcsLogLevelDefinition levelJacORB = AcsLogLevelDefinition.fromInteger(loggingSpec.getJacorbLevelMin());
    List<Throwable> errors = new ArrayList<Throwable>();
    try {
        for (ContainerSpecT containerSpec : pubSubSpec.getContainer()) {
            // start containers sequentially (TODO: with thread pool)
            String host = (containerSpec.getHostName() != null ? containerSpec.getHostName() : localhostName);
            String containerName = containerSpec.getContainerName();
            m_logger.fine("about to start container " + containerName + " on host " + (host == null ? "localhost" : host));
            ContainerImplLangType implLang = ContainerImplLangType.valueOf(containerSpec.getImplLang().toString());
            containerUtil.startContainer(host, implLang, containerName, null, true);
            // configure container log levels
            ContainerLogLevelSpec contLogLevelSpec = new ContainerLogLevelSpec(levelDefault, levelDefaultLocal);
            contLogLevelSpec.addNamedLoggerSpec("jacorb@" + containerName, levelJacORB, levelJacORB);
            containerUtil.setContainerLogLevels(containerName, contLogLevelSpec);
            m_logger.info("started container " + containerName + " on host " + (host == null ? "localhost" : host));
        }
    } catch (Throwable thr) {
        errors.add(thr);
    }
    boolean allPubSubHaveFiniteEvents = true;
    ExecutorService pubSubExec = Executors.newCachedThreadPool(getContainerServices().getThreadFactory());
    if (errors.isEmpty()) {
        for (final SubscriberSpecT subSpec : pubSubSpec.getSubscriber()) {
            boolean subIsBlocking = isBlocking(subSpec);
            if (!subIsBlocking) {
                allPubSubHaveFiniteEvents = false;
            }
            ImplLangT implLang = deriveComponentImplLang(subSpec, pubSubSpec);
            // TODO: pack this into one call, now that the comp will fail on the second call !!!
            if (componentAccessUtil.getCachedComponentNames().contains(subSpec.getComponentName())) {
                m_logger.info("Multiple subscribers specified for component " + subSpec.getComponentName() + ". This is legal, but unusual. Some values may be overwritten.");
            }
            CorbaNotifyConsumerOperations subscriberComp = componentAccessUtil.getDynamicSubscriberComponent(subSpec.getComponentName(), subSpec.getContainerName(), implLang);
            if (subSpec.hasLogMultiplesOfEventCount()) {
                subscriberComp.setEventLogging(subSpec.getLogMultiplesOfEventCount());
            }
            PubSubRunner runner = new PubSubRunner(subSpec, subscriberComp, pubSubExec, m_logger) {

                @Override
                protected Integer callSpecific(NcEventSpec eventSpec, int numEvents) throws CouldntPerformActionEx {
                    logger.info("About to call subscriber#receiveEvents...");
                    int processingDelay = (subSpec.hasProcessingDelayMillis() ? subSpec.getProcessingDelayMillis() : -1);
                    return ((CorbaNotifyConsumerOperations) pubSubComp).receiveEvents(new NcEventSpec[] { eventSpec }, processingDelay, numEvents);
                }
            };
            try {
                runner.runPubSub();
            } catch (Exception ex) {
                errors.add(ex);
            }
        }
        // to "ensure" that even the asynchronously called subscribers are ready before we publish events
        Thread.sleep(100);
        for (final PublisherSpecT pubSpec : pubSubSpec.getPublisher()) {
            boolean pubIsBlocking = isBlocking(pubSpec);
            if (!pubIsBlocking) {
                allPubSubHaveFiniteEvents = false;
            }
            ImplLangT implLang = deriveComponentImplLang(pubSpec, pubSubSpec);
            // (which will result in multiple NCPublisher instances created by that component).
            if (componentAccessUtil.getCachedComponentNames().contains(pubSpec.getComponentName())) {
                m_logger.info("Multiple publishers specified for component " + pubSpec.getComponentName() + ". This is legal, but unusual. Some values may be overwritten.");
            }
            CorbaNotifySupplierOperations publisherComp = componentAccessUtil.getDynamicSupplierComponent(pubSpec.getComponentName(), pubSpec.getContainerName(), implLang);
            if (pubSpec.hasLogMultiplesOfEventCount()) {
                publisherComp.setEventLogging(pubSpec.getLogMultiplesOfEventCount());
            }
            PubSubRunner runner = new PubSubRunner(pubSpec, publisherComp, pubSubExec, m_logger) {

                @Override
                protected Integer callSpecific(NcEventSpec eventSpec, int numEvents) throws CouldntPerformActionEx {
                    logger.info("About to call publisher#sendEvents...");
                    int eventPeriodMillis = (pubSpec.hasEventPeriodMillis() ? pubSpec.getEventPeriodMillis() : -1);
                    return ((CorbaNotifySupplierOperations) pubSubComp).sendEvents(new NcEventSpec[] { eventSpec }, eventPeriodMillis, numEvents);
                }
            };
            try {
                runner.runPubSub();
            } catch (Exception ex) {
                errors.add(ex);
            }
        }
    }
    // wait for NC scenario to execute
    if (errors.isEmpty()) {
        if (allPubSubHaveFiniteEvents) {
            // wait for all suppliers and subscribers to finish, enforcing the timeout if applicable
            // TODO: More options would be available if we stored the PubSubRunner instances in a list...
            pubSubExec.shutdown();
            if (executionTimeMax > 0) {
                pubSubExec.awaitTermination(executionTimeMax, executionTimeMaxUnit);
            } else {
                // like Dornroeschen
                pubSubExec.awaitTermination(100 * 365, TimeUnit.DAYS);
            }
        } else {
            // even if some others should terminate by themselves
            if (executionTimeMax > 0) {
                try {
                    m_logger.info("Will sleep for " + executionTimeMax + " " + executionTimeMaxUnit.toString().toLowerCase() + "...");
                    executionTimeMaxUnit.sleep(executionTimeMax);
                } catch (Exception ex) {
                    errors.add(ex);
                }
            // now also the finite suppliers/subscribers should be finished, but even if not they will get interrupted
            // along with the infinite ones in the cleanup.
            } else {
                errors.add(new IllegalArgumentException("An execution time must be specified if some publisher or subscriber is configured with an infinite number of events. Terminating right away..."));
            }
        }
    }
    // cleanup
    m_logger.info("Will clean up the pub/sub components...");
    // interrupt and release all components
    for (ACSComponentOperations comp : componentAccessUtil.getCachedComponents()) {
        // we could avoid the casting if we keep a separate list of subscriber and supplier comps...
        if (comp instanceof CorbaNotifyCompBaseOperations) {
            CorbaNotifyCompBaseOperations pubSubComp = (CorbaNotifyCompBaseOperations) comp;
            pubSubComp.ncDisconnect();
        }
    }
    componentAccessUtil.releaseAllComponents(true);
    // stop containers
    for (ContainerSpecT containerSpec : pubSubSpec.getContainer()) {
        try {
            String host = (containerSpec.getHostName() != null ? containerSpec.getHostName() : localhostName);
            String containerName = containerSpec.getContainerName();
            m_logger.fine("about to stop container " + containerName + " on host " + (host == null ? "localhost" : host));
            containerUtil.stopContainer(host, containerName);
            m_logger.info("stopped container " + containerName + " on host " + (host == null ? "localhost" : host));
        } catch (Throwable thr) {
            errors.add(thr);
        }
    }
    if (!errors.isEmpty()) {
        m_logger.severe("There were " + errors.size() + " errors!");
        throw errors.get(0);
    }
}

Example 13 with AcsLogLevelDefinition

use of alma.acs.logging.level.AcsLogLevelDefinition in project ACS by ACS-Community.

the class AlarmTestComponentImpl method logBurst.

@Override
public void logBurst(short logLevel, int numLogs) throws CouldntPerformActionEx {
    try {
        AcsLogLevelDefinition coreLevel = AcsLogLevelDefinition.fromInteger(logLevel);
        AcsLogLevel level = AcsLogLevel.fromAcsCoreLevel(coreLevel);
        String msg = "Got call to logBurst, with log level=" + coreLevel.name + ", numLogs=" + numLogs;
        msg += ", property alma.acs.logging.lossless=" + System.getProperty("alma.acs.logging.lossless");
        msg += ", maxLogQueueSize=" + ClientLogManager.getAcsLogManager().getLogConfig().getMaxLogQueueSize();
        msg += ", maxLogsPerSecond=" + ClientLogManager.getAcsLogManager().getLogConfig().getMaxLogsPerSecond() + ".";
        m_logger.info(msg);
        // sleep a bit, so that the above log gets processed before the alarm throttle can remove it.
        Thread.sleep(100);
        for (int i = 0; i < numLogs; i++) {
            m_logger.log(level, "Test log (" + coreLevel.toString() + ") #" + i);
        }
    } catch (Exception ex) {
        throw (new AcsJCouldntPerformActionEx(ex)).toCouldntPerformActionEx();
    } finally {
        // seem to justify adding an "evaluation thread" to the LogThrottle.
        try {
            Thread.sleep(1000);
        } catch (InterruptedException ex) {
            ex.printStackTrace();
        }
    }
}

Example 14 with AcsLogLevelDefinition

use of alma.acs.logging.level.AcsLogLevelDefinition in project ACS by ACS-Community.

the class ContainerLoggingAlarmTest method testLogOverflowNoThrottle.

/**
	 */
@Test
public void testLogOverflowNoThrottle() throws Exception {
    String compName = "TestcompJavaUnthrottled";
    int numLogs = 10000;
    // The level must be INFO or higher so that it gets dropped only when the queue is 100% full.
    // DEBUG and below levels get dropped already at 70% full.
    AcsLogLevelDefinition level = AcsLogLevelDefinition.INFO;
    AlarmTestComponent comp = AlarmTestComponentHelper.narrow(getContainerServices().getComponent(compName));
    StopWatch sw = new StopWatch(m_logger);
    comp.logBurst((short) level.value, numLogs);
    sw.logLapTime("send " + numLogs + " " + level.name() + " logs from component " + compName, AcsLogLevel.INFO);
    // now send Debug logs at max speed, to check how they get dropped in the log queue
    numLogs = 1000;
    level = AcsLogLevelDefinition.DEBUG;
    comp.logBurst((short) level.value, numLogs);
    sw.logLapTime("send " + numLogs + " " + level.name() + " logs from component " + compName, AcsLogLevel.INFO);
    // sleep a bit so that the log queue can drain. This gives a chance to see the "no longer dropping" kind of message
    Thread.sleep(2000);
    comp.logBurst((short) level.value, numLogs);
    sw.logLapTime("send " + numLogs + " " + level.name() + " logs from component " + compName, AcsLogLevel.INFO);
    getContainerServices().releaseComponent(compName);
}

Example 15 with AcsLogLevelDefinition

use of alma.acs.logging.level.AcsLogLevelDefinition in project ACS by ACS-Community.

the class ContainerLoggingAlarmTest method testLogThrottleAlarm.

@Test
public void testLogThrottleAlarm() throws Exception {
    int numLogs = 1000;
    AcsLogLevelDefinition level = AcsLogLevelDefinition.DEBUG;
    String compName = "TestcompJavaThrottled";
    AlarmTestComponent comp = AlarmTestComponentHelper.narrow(getContainerServices().getComponent(compName));
    StopWatch sw = new StopWatch(m_logger);
    comp.logBurst((short) level.value, numLogs);
    sw.logLapTime("send " + numLogs + " " + level.name() + " logs from component " + compName, AcsLogLevel.INFO);
    getContainerServices().releaseComponent(compName);
}