Search in sources :

Example 1 with DelayedLogEntry

use of alma.acs.logging.engine.LogReceiver.DelayedLogEntry in project ACS by ACS-Community.

the class LogSeriesExpectant method awaitLogRecords.

/**
	 * Call this method after the logs that should be received have been produced.
	 * Then the call may take up to <code>logRoundtripTimeSeconds</code> seconds to return.  
	 * 
	 * @param loggerName  The name of the logger whose records are to be collected. 
	 *                    Filtering of arriving log records will be done for the {@link ILogEntry.Field#SOURCEOBJECT} field.
	 * @param logRoundtripTimeSeconds  Maximum roundtrip time of a log record 
	 *                                 (incl. caching by container, sending to Log service, processing by Log service, arrival at LogReceiver).
	 */
LogList awaitLogRecords(String loggerName, int logRoundtripTimeSeconds) {
    // doesn't look like we need a running time windows to sort log records as long as we sort the list in the end.
    int sortingTimeWindowSeconds = 0;
    long endTimeMillis = System.currentTimeMillis() + (logRoundtripTimeSeconds + sortingTimeWindowSeconds) * 1000;
    LogList logRecords = new LogList();
    logReceiver.setDelayMillis(sortingTimeWindowSeconds * 1000);
    BlockingQueue<DelayedLogEntry> queue = logReceiver.getLogQueue();
    long waitTimeMillis = -1;
    while ((waitTimeMillis = endTimeMillis - System.currentTimeMillis()) > 0) {
        DelayedLogEntry delayedLogEntry = null;
        try {
            delayedLogEntry = queue.poll(waitTimeMillis, TimeUnit.MILLISECONDS);
        } catch (InterruptedException ex) {
        // continue
        }
        if (delayedLogEntry != null) {
            // timeout yields a null
            ReceivedLogRecord logRecord = delayedLogEntry.getLogRecord();
            String sourceObjectName = logRecord.getSourceObject();
            if (sourceObjectName != null && sourceObjectName.equals(loggerName)) {
                // printing this could be useful for debugging the test
                System.out.println("TEST DEBUG: " + logRecord.getMessage());
                if (logRecord.getMessage() == null) {
                    System.out.println("BUG: got a null log-message from " + sourceObjectName);
                    continue;
                }
                // Filter out python trace-logs (which could make it or not, depending on timing)
                if (logRecord.getMessage().startsWith("initialize -") || logRecord.getMessage().startsWith("getLevels -") || logRecord.getMessage().startsWith("cleanUp -")) {
                    //System.out.println("Dropping this log: "+ logRecord.getMessage());
                    continue;
                }
                // Filter out messages which are a work-around for a python issue 
                if (!logRecord.getMessage().endsWith("===packet fill-up message===")) {
                    logRecords.add(logRecord);
                }
            } else {
            // printing this could be useful for debugging the test
            //System.out.println("Dropped log message from " + sourceObjectName + ": " + logRecord.getMessage());
            //System.out.println("Dropped log message from " + sourceObjectName + ": " + logEntry.getField(ILogEntry.Field.LOGMESSAGE));
            }
        }
    }
    // sort by timestamp
    Collections.sort(logRecords, new Comparator<ReceivedLogRecord>() {

        public int compare(ReceivedLogRecord o1, ReceivedLogRecord o2) {
            return o1.getTimestamp().compareTo(o2.getTimestamp());
        }
    });
    return logRecords;
}
Also used : DelayedLogEntry(alma.acs.logging.engine.LogReceiver.DelayedLogEntry) ReceivedLogRecord(alma.acs.logging.engine.LogReceiver.ReceivedLogRecord)

Example 2 with DelayedLogEntry

use of alma.acs.logging.engine.LogReceiver.DelayedLogEntry 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();
}
Also used : Random(java.util.Random) AcsLogLevelDefinition(alma.acs.logging.level.AcsLogLevelDefinition) AcsLogLevel(alma.acs.logging.AcsLogLevel) Level(java.util.logging.Level) DelayedLogEntry(alma.acs.logging.engine.LogReceiver.DelayedLogEntry) LogConfig(alma.acs.logging.config.LogConfig) LogReceiver(alma.acs.logging.engine.LogReceiver)

Aggregations

DelayedLogEntry (alma.acs.logging.engine.LogReceiver.DelayedLogEntry)2 AcsLogLevel (alma.acs.logging.AcsLogLevel)1 LogConfig (alma.acs.logging.config.LogConfig)1 LogReceiver (alma.acs.logging.engine.LogReceiver)1 ReceivedLogRecord (alma.acs.logging.engine.LogReceiver.ReceivedLogRecord)1 AcsLogLevelDefinition (alma.acs.logging.level.AcsLogLevelDefinition)1 Random (java.util.Random)1 Level (java.util.logging.Level)1