Skip to content

Commit 5a1d084

Browse files
trasktrask
authored
Fix request exception not captured when INSTRUMENTATION_LOGGING_LEVEL=OFF (#4130)
1 parent 43ca719 commit 5a1d084

File tree

11 files changed

+396
-191
lines changed

11 files changed

+396
-191
lines changed

‎.github/workflows/build-common.yml

+12
Original file line numberDiff line numberDiff line change
@@ -216,3 +216,15 @@ jobs:
216216

217217
- name: Test
218218
run: ./gradlew ${{ matrix.module }}:smokeTest
219+
220+
- name: Create unique artifact name
221+
if: failure()
222+
run: |
223+
echo "UPLOAD_ARTIFACT_NAME=${{ matrix.module }}" | sed 's/:/-/g' >> $GITHUB_ENV
224+
225+
- name: Upload smoke test reports
226+
uses: actions/upload-artifact@v4
227+
if: failure()
228+
with:
229+
name: ${{ env.UPLOAD_ARTIFACT_NAME }}
230+
path: '**/build/reports/tests/smokeTest/**/*'

‎agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/exporter/AgentLogExporter.java

+3-60
Original file line numberDiff line numberDiff line change
@@ -10,23 +10,16 @@
1010
import com.azure.monitor.opentelemetry.autoconfigure.implementation.logging.OperationLogger;
1111
import com.azure.monitor.opentelemetry.autoconfigure.implementation.models.TelemetryItem;
1212
import com.azure.monitor.opentelemetry.autoconfigure.implementation.quickpulse.QuickPulse;
13-
import com.microsoft.applicationinsights.agent.internal.configuration.Configuration.SamplingOverride;
14-
import com.microsoft.applicationinsights.agent.internal.sampling.AiFixedPercentageSampler;
15-
import com.microsoft.applicationinsights.agent.internal.sampling.SamplingOverrides;
1613
import com.microsoft.applicationinsights.agent.internal.telemetry.BatchItemProcessor;
1714
import com.microsoft.applicationinsights.agent.internal.telemetry.TelemetryClient;
1815
import com.microsoft.applicationinsights.agent.internal.telemetry.TelemetryObservers;
1916
import io.opentelemetry.api.logs.LoggerProvider;
20-
import io.opentelemetry.api.trace.SpanContext;
2117
import io.opentelemetry.javaagent.bootstrap.CallDepth;
2218
import io.opentelemetry.sdk.common.CompletableResultCode;
2319
import io.opentelemetry.sdk.logs.data.LogRecordData;
2420
import io.opentelemetry.sdk.logs.export.LogRecordExporter;
25-
import io.opentelemetry.sdk.trace.samplers.SamplingDecision;
26-
import io.opentelemetry.sdk.trace.samplers.SamplingResult;
2721
import io.opentelemetry.semconv.ExceptionAttributes;
2822
import java.util.Collection;
29-
import java.util.List;
3023
import java.util.function.Consumer;
3124
import javax.annotation.Nullable;
3225
import org.slf4j.Logger;
@@ -39,24 +32,13 @@ public class AgentLogExporter implements LogRecordExporter {
3932
private static final OperationLogger exportingLogLogger =
4033
new OperationLogger(AgentLogExporter.class, "Exporting log");
4134

42-
// TODO (trask) could implement this in a filtering LogExporter instead
43-
private volatile int severityThreshold;
44-
45-
private final SamplingOverrides logSamplingOverrides;
46-
private final SamplingOverrides exceptionSamplingOverrides;
4735
private final LogDataMapper mapper;
4836
private final Consumer<TelemetryItem> telemetryItemConsumer;
4937

5038
public AgentLogExporter(
51-
int severityThreshold,
52-
List<SamplingOverride> logSamplingOverrides,
53-
List<SamplingOverride> exceptionSamplingOverrides,
5439
LogDataMapper mapper,
5540
@Nullable QuickPulse quickPulse,
5641
BatchItemProcessor batchItemProcessor) {
57-
this.severityThreshold = severityThreshold;
58-
this.logSamplingOverrides = new SamplingOverrides(logSamplingOverrides);
59-
this.exceptionSamplingOverrides = new SamplingOverrides(exceptionSamplingOverrides);
6042
this.mapper = mapper;
6143
telemetryItemConsumer =
6244
telemetryItem -> {
@@ -70,10 +52,6 @@ public AgentLogExporter(
7052
};
7153
}
7254

73-
public void setSeverityThreshold(int severityThreshold) {
74-
this.severityThreshold = severityThreshold;
75-
}
76-
7755
@Override
7856
public CompletableResultCode export(Collection<LogRecordData> logs) {
7957
// incrementing CallDepth for LoggerProvider causes the OpenTelemetry Java agent logging
@@ -107,47 +85,12 @@ private CompletableResultCode internalExport(Collection<LogRecordData> logs) {
10785

10886
private void internalExport(LogRecordData log) {
10987
try {
110-
int severityNumber = log.getSeverity().getSeverityNumber();
111-
if (severityNumber < severityThreshold) {
112-
return;
113-
}
88+
logger.debug("exporting log: {}", log);
11489

11590
String stack = log.getAttributes().get(ExceptionAttributes.EXCEPTION_STACKTRACE);
91+
Double sampleRate = log.getAttributes().get(AiSemanticAttributes.SAMPLE_RATE);
11692

117-
SamplingOverrides samplingOverrides =
118-
stack != null ? exceptionSamplingOverrides : logSamplingOverrides;
119-
120-
SpanContext spanContext = log.getSpanContext();
121-
Double parentSpanSampleRate = log.getAttributes().get(AiSemanticAttributes.SAMPLE_RATE);
122-
123-
AiFixedPercentageSampler sampler = samplingOverrides.getOverride(log.getAttributes());
124-
125-
boolean hasSamplingOverride = sampler != null;
126-
127-
if (!hasSamplingOverride
128-
&& spanContext.isValid()
129-
&& !spanContext.getTraceFlags().isSampled()) {
130-
// if there is no sampling override, and the log is part of an unsampled trace,
131-
// then don't capture it
132-
return;
133-
}
134-
135-
Double sampleRate = null;
136-
if (hasSamplingOverride) {
137-
SamplingResult samplingResult = sampler.shouldSampleLog(spanContext, parentSpanSampleRate);
138-
if (samplingResult.getDecision() != SamplingDecision.RECORD_AND_SAMPLE) {
139-
return;
140-
}
141-
sampleRate = samplingResult.getAttributes().get(AiSemanticAttributes.SAMPLE_RATE);
142-
}
143-
144-
if (sampleRate == null) {
145-
sampleRate = parentSpanSampleRate;
146-
}
147-
148-
logger.debug("exporting log: {}", log);
149-
150-
// TODO (trask) no longer need to check AiSemanticAttributes.SAMPLE_RATE in map() method
93+
// TODO (trask) get stack and sampleRate inside map() method instead of passing into
15194
TelemetryItem telemetryItem = mapper.map(log, stack, sampleRate);
15295
telemetryItemConsumer.accept(telemetryItem);
15396

‎agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/init/AzureMonitorLogFilteringProcessor.java

+191
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,191 @@
1+
// Copyright (c) Microsoft Corporation. All rights reserved.
2+
// Licensed under the MIT License.
3+
4+
package com.microsoft.applicationinsights.agent.internal.init;
5+
6+
import com.azure.core.util.logging.ClientLogger;
7+
import com.azure.monitor.opentelemetry.autoconfigure.implementation.AiSemanticAttributes;
8+
import com.microsoft.applicationinsights.agent.internal.configuration.Configuration;
9+
import com.microsoft.applicationinsights.agent.internal.sampling.AiFixedPercentageSampler;
10+
import com.microsoft.applicationinsights.agent.internal.sampling.SamplingOverrides;
11+
import io.opentelemetry.api.trace.Span;
12+
import io.opentelemetry.api.trace.SpanContext;
13+
import io.opentelemetry.context.Context;
14+
import io.opentelemetry.instrumentation.api.instrumenter.LocalRootSpan;
15+
import io.opentelemetry.sdk.common.CompletableResultCode;
16+
import io.opentelemetry.sdk.internal.AttributesMap;
17+
import io.opentelemetry.sdk.logs.LogRecordProcessor;
18+
import io.opentelemetry.sdk.logs.ReadWriteLogRecord;
19+
import io.opentelemetry.sdk.trace.ReadableSpan;
20+
import io.opentelemetry.sdk.trace.samplers.SamplingDecision;
21+
import io.opentelemetry.sdk.trace.samplers.SamplingResult;
22+
import io.opentelemetry.semconv.ExceptionAttributes;
23+
import java.lang.reflect.Field;
24+
import java.util.List;
25+
import javax.annotation.Nullable;
26+
27+
public class AzureMonitorLogFilteringProcessor implements LogRecordProcessor {
28+
29+
private static final ClientLogger logger = new ClientLogger(AzureMonitorLogProcessor.class);
30+
private static final Field lockField;
31+
private static final Field attributesMapField;
32+
33+
static {
34+
Class<?> sdkReadWriteLogRecordClass = getSdkReadWriteLogRecordClass();
35+
lockField = getLockField(sdkReadWriteLogRecordClass);
36+
attributesMapField = getAttributesMapField(sdkReadWriteLogRecordClass);
37+
}
38+
39+
private final SamplingOverrides logSamplingOverrides;
40+
private final SamplingOverrides exceptionSamplingOverrides;
41+
private final LogRecordProcessor batchLogRecordProcessor;
42+
43+
private volatile int severityThreshold;
44+
45+
public AzureMonitorLogFilteringProcessor(
46+
List<Configuration.SamplingOverride> logSamplingOverrides,
47+
List<Configuration.SamplingOverride> exceptionSamplingOverrides,
48+
LogRecordProcessor batchLogRecordProcessor,
49+
int severityThreshold) {
50+
51+
this.severityThreshold = severityThreshold;
52+
this.logSamplingOverrides = new SamplingOverrides(logSamplingOverrides);
53+
this.exceptionSamplingOverrides = new SamplingOverrides(exceptionSamplingOverrides);
54+
this.batchLogRecordProcessor = batchLogRecordProcessor;
55+
this.severityThreshold = severityThreshold;
56+
}
57+
58+
public void setSeverityThreshold(int severityThreshold) {
59+
this.severityThreshold = severityThreshold;
60+
}
61+
62+
@Override
63+
public void onEmit(Context context, ReadWriteLogRecord logRecord) {
64+
65+
int severityNumber = logRecord.getSeverity().getSeverityNumber();
66+
if (severityNumber < severityThreshold) {
67+
// quick return
68+
return;
69+
}
70+
71+
Double parentSpanSampleRate = null;
72+
Span currentSpan = Span.fromContext(context);
73+
if (currentSpan instanceof ReadableSpan) {
74+
ReadableSpan readableSpan = (ReadableSpan) currentSpan;
75+
parentSpanSampleRate = readableSpan.getAttribute(AiSemanticAttributes.SAMPLE_RATE);
76+
}
77+
78+
// deal with sampling synchronously so that we only call setAttributeExceptionLogged()
79+
// when we know we are emitting the exception (span sampling happens synchronously as well)
80+
81+
String stack = logRecord.getAttribute(ExceptionAttributes.EXCEPTION_STACKTRACE);
82+
83+
SamplingOverrides samplingOverrides =
84+
stack != null ? exceptionSamplingOverrides : logSamplingOverrides;
85+
86+
SpanContext spanContext = logRecord.getSpanContext();
87+
88+
AiFixedPercentageSampler sampler = samplingOverrides.getOverride(logRecord.getAttributes());
89+
90+
boolean hasSamplingOverride = sampler != null;
91+
92+
if (!hasSamplingOverride && spanContext.isValid() && !spanContext.getTraceFlags().isSampled()) {
93+
// if there is no sampling override, and the log is part of an unsampled trace,
94+
// then don't capture it
95+
return;
96+
}
97+
98+
Double sampleRate = null;
99+
if (hasSamplingOverride) {
100+
SamplingResult samplingResult = sampler.shouldSampleLog(spanContext, parentSpanSampleRate);
101+
if (samplingResult.getDecision() != SamplingDecision.RECORD_AND_SAMPLE) {
102+
return;
103+
}
104+
sampleRate = samplingResult.getAttributes().get(AiSemanticAttributes.SAMPLE_RATE);
105+
}
106+
107+
if (sampleRate == null) {
108+
sampleRate = parentSpanSampleRate;
109+
}
110+
111+
if (sampleRate != null) {
112+
logRecord.setAttribute(AiSemanticAttributes.SAMPLE_RATE, sampleRate);
113+
}
114+
115+
setAttributeExceptionLogged(LocalRootSpan.fromContext(context), logRecord);
116+
117+
batchLogRecordProcessor.onEmit(context, logRecord);
118+
}
119+
120+
@Override
121+
public CompletableResultCode shutdown() {
122+
return batchLogRecordProcessor.shutdown();
123+
}
124+
125+
@Override
126+
public CompletableResultCode forceFlush() {
127+
return batchLogRecordProcessor.forceFlush();
128+
}
129+
130+
@Override
131+
public void close() {
132+
batchLogRecordProcessor.close();
133+
}
134+
135+
@Nullable
136+
private static Class<?> getSdkReadWriteLogRecordClass() {
137+
try {
138+
return Class.forName("io.opentelemetry.sdk.logs.SdkReadWriteLogRecord");
139+
} catch (ClassNotFoundException e) {
140+
return null;
141+
}
142+
}
143+
144+
@Nullable
145+
private static Field getLockField(Class<?> sdkReadWriteLogRecordClass) {
146+
if (sdkReadWriteLogRecordClass == null) {
147+
return null;
148+
}
149+
try {
150+
Field lockField = sdkReadWriteLogRecordClass.getDeclaredField("lock");
151+
lockField.setAccessible(true);
152+
return lockField;
153+
} catch (NoSuchFieldException e) {
154+
return null;
155+
}
156+
}
157+
158+
@Nullable
159+
private static Field getAttributesMapField(Class<?> sdkReadWriteLogRecordClass) {
160+
if (sdkReadWriteLogRecordClass == null) {
161+
return null;
162+
}
163+
try {
164+
Field attributesMapField = sdkReadWriteLogRecordClass.getDeclaredField("attributes");
165+
attributesMapField.setAccessible(true);
166+
return attributesMapField;
167+
} catch (NoSuchFieldException e) {
168+
return null;
169+
}
170+
}
171+
172+
private static void setAttributeExceptionLogged(Span span, ReadWriteLogRecord logRecord) {
173+
if (lockField == null || attributesMapField == null) {
174+
return;
175+
}
176+
String stacktrace = null;
177+
try {
178+
synchronized (lockField) {
179+
// TODO add `getAttribute()` to `ReadWriteLogRecord` upstream
180+
stacktrace =
181+
((AttributesMap) attributesMapField.get(logRecord))
182+
.get(ExceptionAttributes.EXCEPTION_STACKTRACE);
183+
}
184+
} catch (Exception e) {
185+
logger.error(e.getMessage(), e);
186+
}
187+
if (stacktrace != null) {
188+
span.setAttribute(AiSemanticAttributes.LOGGED_EXCEPTION, stacktrace);
189+
}
190+
}
191+
}

0 commit comments

Comments
 (0)