Skip to content

Commit

Permalink
Make log record asserts similar to trace asserts
Browse files Browse the repository at this point in the history
  • Loading branch information
@laurit
laurit committed Sep 4, 2024
1 parent d9f7030 commit c57abb1
Show file tree
Hide file tree
Showing 14 changed files with 690 additions and 616 deletions.
104 changes: 58 additions & 46 deletions ...elemetry/javaagent/instrumentation/jbosslogmanager/appender/v1_1/JbossLogmanagerTest.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -9,18 +9,23 @@
import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.equalTo;
import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.satisfies;
import static java.util.concurrent.TimeUnit.MILLISECONDS;
import static org.assertj.core.api.Assertions.assertThat;

import io.opentelemetry.api.common.AttributeKey;
import io.opentelemetry.api.logs.Severity;
import io.opentelemetry.api.trace.SpanContext;
import io.opentelemetry.instrumentation.testing.junit.AgentInstrumentationExtension;
import io.opentelemetry.instrumentation.testing.junit.InstrumentationExtension;
import io.opentelemetry.sdk.common.InstrumentationScopeInfo;
import io.opentelemetry.sdk.logs.data.LogRecordData;
import io.opentelemetry.sdk.testing.assertj.AttributeAssertion;
import io.opentelemetry.semconv.ExceptionAttributes;
import io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes;
import java.time.Instant;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.List;
import java.util.stream.Stream;
import org.assertj.core.api.AssertAccess;
import org.jboss.logmanager.Level;
import org.jboss.logmanager.LogContext;
import org.jboss.logmanager.Logger;
Expand Down Expand Up @@ -127,40 +132,45 @@ private static void test(
}

if (expectedSeverity != null) {
LogRecordData log = testing.waitForLogRecords(1).get(0);
assertThat(log)
.hasBody(withParam ? "xyz: 123" : "xyz")
.hasInstrumentationScope(InstrumentationScopeInfo.builder(expectedLoggerName).build())
.hasSeverity(expectedSeverity)
.hasSeverityText(expectedSeverityText);

assertThat(log.getTimestampEpochNanos())
.isGreaterThanOrEqualTo(MILLISECONDS.toNanos(start.toEpochMilli()))
.isLessThanOrEqualTo(MILLISECONDS.toNanos(Instant.now().toEpochMilli()));

if (logException) {
assertThat(log)
.hasAttributesSatisfyingExactly(
equalTo(ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId()),
equalTo(ExceptionAttributes.EXCEPTION_TYPE, IllegalStateException.class.getName()),
equalTo(ExceptionAttributes.EXCEPTION_MESSAGE, "hello"),
satisfies(
ExceptionAttributes.EXCEPTION_STACKTRACE,
v -> v.contains(JbossLogmanagerTest.class.getName())));
} else {
assertThat(log)
.hasAttributesSatisfyingExactly(
equalTo(ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId()));
}

if (withParent) {
assertThat(log).hasSpanContext(testing.spans().get(0).getSpanContext());
} else {
assertThat(log.getSpanContext().isValid()).isFalse();
}

testing.waitAndAssertLogRecords(
logRecord -> {
logRecord
.hasBody(withParam ? "xyz: 123" : "xyz")
.hasInstrumentationScope(
InstrumentationScopeInfo.builder(expectedLoggerName).build())
.hasSeverity(expectedSeverity)
.hasSeverityText(expectedSeverityText)
.hasSpanContext(
withParent
? testing.spans().get(0).getSpanContext()
: SpanContext.getInvalid());

List<AttributeAssertion> attributeAsserts =
new ArrayList<>(
Arrays.asList(
equalTo(
ThreadIncubatingAttributes.THREAD_NAME,
Thread.currentThread().getName()),
equalTo(
ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
if (logException) {
attributeAsserts.addAll(
Arrays.asList(
equalTo(
ExceptionAttributes.EXCEPTION_TYPE,
IllegalStateException.class.getName()),
equalTo(ExceptionAttributes.EXCEPTION_MESSAGE, "hello"),
satisfies(
ExceptionAttributes.EXCEPTION_STACKTRACE,
v -> v.contains(JbossLogmanagerTest.class.getName()))));
}
logRecord.hasAttributesSatisfyingExactly(attributeAsserts);

LogRecordData logRecordData = AssertAccess.getActual(logRecord);
assertThat(logRecordData.getTimestampEpochNanos())
.isGreaterThanOrEqualTo(MILLISECONDS.toNanos(start.toEpochMilli()))
.isLessThanOrEqualTo(MILLISECONDS.toNanos(Instant.now().toEpochMilli()));
});
} else {
Thread.sleep(500); // sleep a bit just to make sure no log is captured
assertThat(testing.logRecords()).isEmpty();
Expand Down Expand Up @@ -199,17 +209,19 @@ void testMdc() {
MDC.remove("key2");
}

LogRecordData log = testing.waitForLogRecords(1).get(0);
assertThat(log)
.hasBody("xyz")
.hasInstrumentationScope(InstrumentationScopeInfo.builder("abc").build())
.hasSeverity(Severity.INFO)
.hasSeverityText("INFO")
.hasAttributesSatisfyingExactly(
equalTo(AttributeKey.stringKey("key1"), "val1"),
equalTo(AttributeKey.stringKey("key2"), "val2"),
equalTo(ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId()));
testing.waitAndAssertLogRecords(
logRecord ->
logRecord
.hasBody("xyz")
.hasInstrumentationScope(InstrumentationScopeInfo.builder("abc").build())
.hasSeverity(Severity.INFO)
.hasSeverityText("INFO")
.hasAttributesSatisfyingExactly(
equalTo(AttributeKey.stringKey("key1"), "val1"),
equalTo(AttributeKey.stringKey("key2"), "val2"),
equalTo(
ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
}

@FunctionalInterface
Expand Down
103 changes: 58 additions & 45 deletions ...aagent/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v1_2/Log4j1Test.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -12,18 +12,24 @@

import io.opentelemetry.api.common.AttributeKey;
import io.opentelemetry.api.logs.Severity;
import io.opentelemetry.api.trace.SpanContext;
import io.opentelemetry.instrumentation.testing.junit.AgentInstrumentationExtension;
import io.opentelemetry.instrumentation.testing.junit.InstrumentationExtension;
import io.opentelemetry.sdk.common.InstrumentationScopeInfo;
import io.opentelemetry.sdk.logs.data.LogRecordData;
import io.opentelemetry.sdk.testing.assertj.AttributeAssertion;
import io.opentelemetry.semconv.ExceptionAttributes;
import io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes;
import java.lang.reflect.Field;
import java.time.Instant;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.List;
import java.util.stream.Stream;
import org.apache.log4j.Logger;
import org.apache.log4j.MDC;
import org.apache.log4j.helpers.Loader;
import org.assertj.core.api.AssertAccess;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.extension.RegisterExtension;
import org.junit.jupiter.params.ParameterizedTest;
Expand Down Expand Up @@ -98,40 +104,45 @@ private static void test(
}

if (expectedSeverity != null) {
LogRecordData log = testing.waitForLogRecords(1).get(0);
assertThat(log)
.hasBody("xyz")
.hasInstrumentationScope(InstrumentationScopeInfo.builder(expectedLoggerName).build())
.hasSeverity(expectedSeverity)
.hasSeverityText(expectedSeverityText);

assertThat(log.getTimestampEpochNanos())
.isGreaterThanOrEqualTo(MILLISECONDS.toNanos(start.toEpochMilli()))
.isLessThanOrEqualTo(MILLISECONDS.toNanos(Instant.now().toEpochMilli()));

if (logException) {
assertThat(log)
.hasAttributesSatisfyingExactly(
equalTo(ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId()),
equalTo(ExceptionAttributes.EXCEPTION_TYPE, IllegalStateException.class.getName()),
equalTo(ExceptionAttributes.EXCEPTION_MESSAGE, "hello"),
satisfies(
ExceptionAttributes.EXCEPTION_STACKTRACE,
v -> v.contains(Log4j1Test.class.getName())));
} else {
assertThat(log)
.hasAttributesSatisfyingExactly(
equalTo(ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId()));
}

if (withParent) {
assertThat(log).hasSpanContext(testing.spans().get(0).getSpanContext());
} else {
assertThat(log.getSpanContext().isValid()).isFalse();
}

testing.waitAndAssertLogRecords(
logRecord -> {
logRecord
.hasBody("xyz")
.hasInstrumentationScope(
InstrumentationScopeInfo.builder(expectedLoggerName).build())
.hasSeverity(expectedSeverity)
.hasSeverityText(expectedSeverityText)
.hasSpanContext(
withParent
? testing.spans().get(0).getSpanContext()
: SpanContext.getInvalid());

List<AttributeAssertion> attributeAsserts =
new ArrayList<>(
Arrays.asList(
equalTo(
ThreadIncubatingAttributes.THREAD_NAME,
Thread.currentThread().getName()),
equalTo(
ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
if (logException) {
attributeAsserts.addAll(
Arrays.asList(
equalTo(
ExceptionAttributes.EXCEPTION_TYPE,
IllegalStateException.class.getName()),
equalTo(ExceptionAttributes.EXCEPTION_MESSAGE, "hello"),
satisfies(
ExceptionAttributes.EXCEPTION_STACKTRACE,
v -> v.contains(Log4j1Test.class.getName()))));
}
logRecord.hasAttributesSatisfyingExactly(attributeAsserts);

LogRecordData logRecordData = AssertAccess.getActual(logRecord);
assertThat(logRecordData.getTimestampEpochNanos())
.isGreaterThanOrEqualTo(MILLISECONDS.toNanos(start.toEpochMilli()))
.isLessThanOrEqualTo(MILLISECONDS.toNanos(Instant.now().toEpochMilli()));
});
} else {
Thread.sleep(500); // sleep a bit just to make sure no log is captured
assertThat(testing.logRecords()).isEmpty();
Expand All @@ -149,17 +160,19 @@ void testMdc() {
MDC.remove("key2");
}

LogRecordData log = testing.waitForLogRecords(1).get(0);
assertThat(log)
.hasBody("xyz")
.hasInstrumentationScope(InstrumentationScopeInfo.builder("abc").build())
.hasSeverity(Severity.INFO)
.hasSeverityText("INFO")
.hasAttributesSatisfyingExactly(
equalTo(AttributeKey.stringKey("key1"), "val1"),
equalTo(AttributeKey.stringKey("key2"), "val2"),
equalTo(ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId()));
testing.waitAndAssertLogRecords(
logRecord ->
logRecord
.hasBody("xyz")
.hasInstrumentationScope(InstrumentationScopeInfo.builder("abc").build())
.hasSeverity(Severity.INFO)
.hasSeverityText("INFO")
.hasAttributesSatisfyingExactly(
equalTo(AttributeKey.stringKey("key1"), "val1"),
equalTo(AttributeKey.stringKey("key2"), "val2"),
equalTo(
ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
}

private static void performLogging(
Expand Down
Loading

0 comments on commit c57abb1

Please sign in to comment.