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;
}
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();
}
Aggregations