From 96712e08248dadafb6a6af6efcfcac509dbdfe85 Mon Sep 17 00:00:00 2001 From: kryalama <66494519+kryalama@users.noreply.github.com> Date: Tue, 9 Feb 2021 19:15:58 -0800 Subject: [PATCH 01/18] initial commit, running code --- .../ActiveTransmissionNetworkOutput.java | 8 ++ .../common/TransmissionNetworkOutput.java | 53 ++++++++++--- .../util/NetworkExceptionsTracker.java | 15 ++++ .../util/NextworkExceptionsTrackerTest.java | 77 +++++++++++++++++++ 4 files changed, 142 insertions(+), 11 deletions(-) create mode 100644 core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java create mode 100644 core/src/test/java/com/microsoft/applicationinsights/internal/util/NextworkExceptionsTrackerTest.java diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java index 674a0c46b17..72f601bfbba 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java @@ -21,7 +21,9 @@ package com.microsoft.applicationinsights.internal.channel.common; +import java.util.concurrent.Executors; import java.util.concurrent.RejectedExecutionException; +import java.util.concurrent.ScheduledExecutorService; import java.util.concurrent.ThreadPoolExecutor; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicInteger; @@ -29,6 +31,8 @@ import com.google.common.base.Preconditions; import com.microsoft.applicationinsights.internal.channel.TransmissionOutputAsync; import com.microsoft.applicationinsights.internal.channel.TransmissionOutputSync; +import com.microsoft.applicationinsights.internal.heartbeat.HeartBeatProvider; +import com.microsoft.applicationinsights.internal.util.NetworkExceptionsTracker; import com.microsoft.applicationinsights.internal.util.ThreadPoolUtils; /** @@ -46,6 +50,8 @@ public final class ActiveTransmissionNetworkOutput implements TransmissionOutput private final TransmissionOutputSync actualOutput; private final TransmissionPolicyStateFetcher transmissionPolicy; private final int instanceId = INTSTANCE_ID_POOL.getAndIncrement(); + private final ScheduledExecutorService networkIssueTracker = + Executors.newSingleThreadScheduledExecutor(ThreadPoolUtils.createDaemonThreadFactory(NetworkExceptionsTracker.class, "networkIssueTracker")); public ActiveTransmissionNetworkOutput(TransmissionOutputSync actualOutput, TransmissionPolicyStateFetcher transmissionPolicy) { this(actualOutput, transmissionPolicy, DEFAULT_MAX_MESSAGES_IN_BUFFER); @@ -56,6 +62,8 @@ public ActiveTransmissionNetworkOutput(TransmissionOutputSync actualOutput, Tran this.actualOutput = actualOutput; this.transmissionPolicy = transmissionPolicy; + // Schedule to run every 5 minutes + this.networkIssueTracker.scheduleAtFixedRate(new NetworkExceptionsTracker(), 0,300, TimeUnit.SECONDS); maxThreads = DEFAULT_MAX_NUMBER_OF_THREADS; outputThreads = ThreadPoolUtils.newLimitedThreadPool( diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java index dd80d1f1d80..d7bbab09952 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java @@ -42,8 +42,11 @@ import javax.annotation.Nullable; import java.io.IOException; import java.net.SocketException; +import java.net.SocketTimeoutException; import java.net.UnknownHostException; import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicInteger; +import java.util.concurrent.atomic.AtomicLong; /** * The class is responsible for the actual sending of @@ -77,6 +80,12 @@ public final class TransmissionNetworkOutput implements TransmissionOutputSync { private TransmissionPolicyManager transmissionPolicyManager; + public static final AtomicLong successCounter = new AtomicLong(0); + public static final AtomicLong failureCounter = new AtomicLong(0); + public static final AtomicLong previousFailureCounter = new AtomicLong(0); + public static final AtomicLong previousSuccessCounter = new AtomicLong(0); + public static final AtomicBoolean firstFailure = new AtomicBoolean(false); + /** * Creates an instance of the network transmission class. * @@ -174,28 +183,32 @@ public boolean sendSync(Transmission transmission) { // to be throttled transmissionPolicyManager.clearBackoff(); } + successCounter.incrementAndGet(); return true; } catch (ConnectionPoolTimeoutException e) { - ex = e; - logger.error("Failed to send, connection pool timeout exception", e); + handleTemporaryExceptions("Failed to send, connection pool timeout exception. " + + "Telemetry will be stored locally and re-sent later once the connection is stable again", e); } catch (SocketException e) { - ex = e; - logger.error("Failed to send, socket exception", e); + handleTemporaryExceptions("Failed to send, socket exception. " + + "Telemetry will be stored locally and re-sent later once the connection is stable again", e); + } catch (SocketTimeoutException e) { + handleTemporaryExceptions("Failed to send, socket timeout exception. " + + "Telemetry will be stored locally and re-sent later once the connection is stable again", e); } catch (UnknownHostException e) { - ex = e; - logger.error("Failed to send, wrong host address or cannot reach address due to network issues", e); - } catch (IOException ioe) { - ex = ioe; - logger.error("Failed to send", ioe); + handleTemporaryExceptions("Failed to send, wrong host address or cannot reach address due to network issues. " + + "Telemetry will be stored locally and re-sent later once the connection is stable again", e); + } catch (IOException e) { + handleTemporaryExceptions("Failed to send, IO exception. " + + "Telemetry will be stored locally and re-sent later once the connection is stable again", e); } catch (FriendlyException e) { ex = e; if(!friendlyExceptionThrown.getAndSet(true)) { logger.error(e.getMessage()); } } catch (Exception e) { - ex = e; - logger.error("Failed to send, unexpected exception", e); + handleTemporaryExceptions("Failed to send, unexpected exception. " + + "Telemetry will be stored locally and re-sent later once the connection is stable again", e); } catch (ThreadDeath td) { throw td; } catch (Throwable t) { @@ -237,6 +250,24 @@ public boolean sendSync(Transmission transmission) { return true; } + private static void handleTemporaryExceptions(String message, Exception ex) { + //Handle first failure + if(!firstFailure.getAndSet(true)) { + logger.error(message+"\n"+ + "Total number of successful telemetry requests so far:"+successCounter.get()+"\n"+ + "Future failures will be aggregated and logged once every 5 minutes\n", + ex + ); + //Log the first failure every 5 minutes. + } else if(failureCounter.getAndIncrement() == 0) { + logger.error(message+"\n"+ + "Total number of failed telemetry requests in the last 5 minutes:"+previousFailureCounter.get()+"\n"+ + "Total number of successful telemetry requests in the last 5 minutes:"+previousFailureCounter.get()+"\n"+ + ex + ); + } + } + /** * Generates the HTTP POST to send to the endpoint. * diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java b/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java new file mode 100644 index 00000000000..6aacdef19f3 --- /dev/null +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java @@ -0,0 +1,15 @@ +package com.microsoft.applicationinsights.internal.util; + +import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.failureCounter; +import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.previousFailureCounter; +import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.previousSuccessCounter; +import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.successCounter; + +public class NetworkExceptionsTracker implements Runnable{ + @Override public void run() { + if(failureCounter.get() > 0) { + previousFailureCounter.set(failureCounter.getAndSet(0)); + previousSuccessCounter.set(successCounter.getAndSet(0)); + } + } +} diff --git a/core/src/test/java/com/microsoft/applicationinsights/internal/util/NextworkExceptionsTrackerTest.java b/core/src/test/java/com/microsoft/applicationinsights/internal/util/NextworkExceptionsTrackerTest.java new file mode 100644 index 00000000000..0367e37ec83 --- /dev/null +++ b/core/src/test/java/com/microsoft/applicationinsights/internal/util/NextworkExceptionsTrackerTest.java @@ -0,0 +1,77 @@ +package com.microsoft.applicationinsights.internal.util; + +import java.util.Timer; +import java.util.TimerTask; +import java.util.concurrent.Executors; +import java.util.concurrent.ScheduledExecutorService; +import java.util.concurrent.TimeUnit; + +import org.junit.*; + +import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.failureCounter; +import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.previousFailureCounter; +import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.previousSuccessCounter; +import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.successCounter; +import static org.junit.Assert.*; + +public class NextworkExceptionsTrackerTest { + private static final ScheduledExecutorService networkIssueTrackerTest = + Executors.newSingleThreadScheduledExecutor( + ThreadPoolUtils.createDaemonThreadFactory( + NetworkExceptionsTracker.class, + "networkIssueTrackerTest")); + + @Before + public void setUp() { + // one-time initialization code + networkIssueTrackerTest.scheduleAtFixedRate(new NetworkExceptionsTracker(), 0, 1, TimeUnit.MILLISECONDS); + } + + @After + public void tearDown() throws InterruptedException { + // one-time cleanup code + if (!networkIssueTrackerTest.isShutdown()) { + networkIssueTrackerTest.shutdown(); + } + networkIssueTrackerTest.awaitTermination(2, TimeUnit.SECONDS); + } + + + @Test + public void testPreviousCountersAreAssigned() throws InterruptedException { + Timer timer = new Timer("Timer"); + TimerTask incrementFailureTask = new TimerTask() { + public void run() { + try { + failureCounter.incrementAndGet(); + Thread.sleep(0); + } catch (InterruptedException e) { + e.printStackTrace(); + } + } + }; + TimerTask incrementSuccessTask = new TimerTask() { + public void run() { + try { + Thread.sleep(0); + successCounter.incrementAndGet(); + } catch (InterruptedException e) { + e.printStackTrace(); + } + + } + }; + Thread failureThread = new Thread(incrementFailureTask); + Thread successThread = new Thread(incrementSuccessTask); + failureThread.start(); + successThread.start(); + assertEquals(0, previousFailureCounter.get()); + assertEquals(0, previousSuccessCounter.get()); + failureThread.join(); + successThread.join(); + assertEquals(1, previousFailureCounter.get()); + assertEquals(1, previousSuccessCounter.get()); + assertEquals(0, successCounter.get()); + assertEquals(0, failureCounter.get()); + } +} From 332a18a13ea560aa2d93779252e3430032c81565 Mon Sep 17 00:00:00 2001 From: kryalama <66494519+kryalama@users.noreply.github.com> Date: Thu, 11 Feb 2021 13:00:00 -0800 Subject: [PATCH 02/18] remove previous counters and generalise handleTemporaryException --- core/build.gradle | 1 + .../common/CommonUtils.java | 20 ++++ .../ActiveTransmissionNetworkOutput.java | 2 +- .../common/TransmissionNetworkOutput.java | 40 ++----- .../util/NetworkExceptionsTracker.java | 31 +++-- .../util/NetworkExceptionsTrackerTest.java | 106 ++++++++++++++++++ .../util/NextworkExceptionsTrackerTest.java | 77 ------------- 7 files changed, 160 insertions(+), 117 deletions(-) create mode 100644 core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java delete mode 100644 core/src/test/java/com/microsoft/applicationinsights/internal/util/NextworkExceptionsTrackerTest.java diff --git a/core/build.gradle b/core/build.gradle index 9889f39c242..50b9507cb50 100644 --- a/core/build.gradle +++ b/core/build.gradle @@ -93,6 +93,7 @@ dependencies { testCompile group: 'junit', name: 'junit', version: '4.12' testCompile group: 'com.google.code.gson', name: 'gson', version: '2.8.2' testCompile group: 'com.github.stefanbirkner', name: 'system-rules', version: '1.19.0' + testCompile group: 'io.github.hakky54', name: 'logcaptor', version: '2.3.1' forTheDLL 'com.microsoft.azure:applicationinsights-core:2.6.2' } diff --git a/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java b/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java index 58895ba01ad..eed83a02693 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java +++ b/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java @@ -23,6 +23,10 @@ import java.net.InetAddress; import java.net.UnknownHostException; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicLong; +import java.util.concurrent.atomic.AtomicReference; + import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -30,6 +34,13 @@ public class CommonUtils { private static final Logger logger = LoggerFactory.getLogger(CommonUtils.class); + public static final AtomicLong successCounter = new AtomicLong(0); + public static final AtomicLong failureCounter = new AtomicLong(0); + public static final AtomicBoolean firstFailure = new AtomicBoolean(false); + public static final AtomicReference lastTemporaryException = new AtomicReference<>(); + public static final AtomicReference lastTemporaryExceptionLogger = new AtomicReference<>(); + public static final AtomicReference lastTemporaryExceptionMessage = new AtomicReference<>(); + public static boolean isNullOrEmpty(String string) { return string == null || string.length() == 0; @@ -68,4 +79,13 @@ public static boolean isClassPresentOnClassPath(String classSignature, ClassLoad return false; } } + + public static void handleTemporaryExceptions(Logger loggerFromException,String message, Exception ex) { + //Handle first failure + if(failureCounter.getAndIncrement() == 0) { + lastTemporaryExceptionMessage.set(message); + lastTemporaryExceptionLogger.set(loggerFromException); + lastTemporaryException.set(ex); + } + } } diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java index 72f601bfbba..3f2f376f95b 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java @@ -63,7 +63,7 @@ public ActiveTransmissionNetworkOutput(TransmissionOutputSync actualOutput, Tran this.actualOutput = actualOutput; this.transmissionPolicy = transmissionPolicy; // Schedule to run every 5 minutes - this.networkIssueTracker.scheduleAtFixedRate(new NetworkExceptionsTracker(), 0,300, TimeUnit.SECONDS); + this.networkIssueTracker.scheduleAtFixedRate(new NetworkExceptionsTracker(), 60,60, TimeUnit.SECONDS); maxThreads = DEFAULT_MAX_NUMBER_OF_THREADS; outputThreads = ThreadPoolUtils.newLimitedThreadPool( diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java index d7bbab09952..a27a0419ca9 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java @@ -45,8 +45,8 @@ import java.net.SocketTimeoutException; import java.net.UnknownHostException; import java.util.concurrent.atomic.AtomicBoolean; -import java.util.concurrent.atomic.AtomicInteger; -import java.util.concurrent.atomic.AtomicLong; +import static com.microsoft.applicationinsights.common.CommonUtils.handleTemporaryExceptions; +import static com.microsoft.applicationinsights.common.CommonUtils.successCounter; /** * The class is responsible for the actual sending of @@ -80,12 +80,6 @@ public final class TransmissionNetworkOutput implements TransmissionOutputSync { private TransmissionPolicyManager transmissionPolicyManager; - public static final AtomicLong successCounter = new AtomicLong(0); - public static final AtomicLong failureCounter = new AtomicLong(0); - public static final AtomicLong previousFailureCounter = new AtomicLong(0); - public static final AtomicLong previousSuccessCounter = new AtomicLong(0); - public static final AtomicBoolean firstFailure = new AtomicBoolean(false); - /** * Creates an instance of the network transmission class. * @@ -187,19 +181,19 @@ public boolean sendSync(Transmission transmission) { return true; } catch (ConnectionPoolTimeoutException e) { - handleTemporaryExceptions("Failed to send, connection pool timeout exception. " + + handleTemporaryExceptions(logger,"Failed to send, connection pool timeout exception. " + "Telemetry will be stored locally and re-sent later once the connection is stable again", e); } catch (SocketException e) { - handleTemporaryExceptions("Failed to send, socket exception. " + + handleTemporaryExceptions(logger,"Failed to send, socket exception. " + "Telemetry will be stored locally and re-sent later once the connection is stable again", e); } catch (SocketTimeoutException e) { - handleTemporaryExceptions("Failed to send, socket timeout exception. " + + handleTemporaryExceptions(logger,"Failed to send, socket timeout exception. " + "Telemetry will be stored locally and re-sent later once the connection is stable again", e); } catch (UnknownHostException e) { - handleTemporaryExceptions("Failed to send, wrong host address or cannot reach address due to network issues. " + + handleTemporaryExceptions(logger,"Failed to send, wrong host address or cannot reach address due to network issues. " + "Telemetry will be stored locally and re-sent later once the connection is stable again", e); } catch (IOException e) { - handleTemporaryExceptions("Failed to send, IO exception. " + + handleTemporaryExceptions(logger,"Failed to send, IO exception. " + "Telemetry will be stored locally and re-sent later once the connection is stable again", e); } catch (FriendlyException e) { ex = e; @@ -207,7 +201,7 @@ public boolean sendSync(Transmission transmission) { logger.error(e.getMessage()); } } catch (Exception e) { - handleTemporaryExceptions("Failed to send, unexpected exception. " + + handleTemporaryExceptions(logger,"Failed to send, unexpected exception. " + "Telemetry will be stored locally and re-sent later once the connection is stable again", e); } catch (ThreadDeath td) { throw td; @@ -250,24 +244,6 @@ public boolean sendSync(Transmission transmission) { return true; } - private static void handleTemporaryExceptions(String message, Exception ex) { - //Handle first failure - if(!firstFailure.getAndSet(true)) { - logger.error(message+"\n"+ - "Total number of successful telemetry requests so far:"+successCounter.get()+"\n"+ - "Future failures will be aggregated and logged once every 5 minutes\n", - ex - ); - //Log the first failure every 5 minutes. - } else if(failureCounter.getAndIncrement() == 0) { - logger.error(message+"\n"+ - "Total number of failed telemetry requests in the last 5 minutes:"+previousFailureCounter.get()+"\n"+ - "Total number of successful telemetry requests in the last 5 minutes:"+previousFailureCounter.get()+"\n"+ - ex - ); - } - } - /** * Generates the HTTP POST to send to the endpoint. * diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java b/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java index 6aacdef19f3..41d6079f37e 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java @@ -1,15 +1,32 @@ package com.microsoft.applicationinsights.internal.util; -import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.failureCounter; -import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.previousFailureCounter; -import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.previousSuccessCounter; -import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.successCounter; + +import static com.microsoft.applicationinsights.common.CommonUtils.failureCounter; +import static com.microsoft.applicationinsights.common.CommonUtils.firstFailure; +import static com.microsoft.applicationinsights.common.CommonUtils.lastTemporaryException; +import static com.microsoft.applicationinsights.common.CommonUtils.lastTemporaryExceptionLogger; +import static com.microsoft.applicationinsights.common.CommonUtils.lastTemporaryExceptionMessage; +import static com.microsoft.applicationinsights.common.CommonUtils.successCounter; public class NetworkExceptionsTracker implements Runnable{ @Override public void run() { - if(failureCounter.get() > 0) { - previousFailureCounter.set(failureCounter.getAndSet(0)); - previousSuccessCounter.set(successCounter.getAndSet(0)); + + if(failureCounter.get() > 0 && lastTemporaryExceptionLogger.get()!=null) { + if(!firstFailure.getAndSet(true)) { + lastTemporaryExceptionLogger.get().error(lastTemporaryExceptionMessage.get()+"\n"+ + "Total number of successful telemetry requests so far:"+successCounter.get()+"\n"+ + "Future failures will be aggregated and logged once every 5 minutes\n", + lastTemporaryException.get() + ); + } else { + lastTemporaryExceptionLogger.get().error(lastTemporaryExceptionMessage.get()+"\n"+ + "Total number of failed telemetry requests in the last 5 minutes:"+failureCounter.get()+"\n"+ + "Total number of successful telemetry requests in the last 5 minutes:"+successCounter.get()+"\n"+ + lastTemporaryException.get() + ); + } + failureCounter.set(0); + successCounter.set(0); } } } diff --git a/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java b/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java new file mode 100644 index 00000000000..4f82609c950 --- /dev/null +++ b/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java @@ -0,0 +1,106 @@ +package com.microsoft.applicationinsights.internal.util; + +import java.util.concurrent.Executors; +import java.util.concurrent.ScheduledExecutorService; +import java.util.concurrent.TimeUnit; + +import nl.altindag.log.LogCaptor; +import org.junit.*; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import static com.microsoft.applicationinsights.common.CommonUtils.failureCounter; +import static com.microsoft.applicationinsights.common.CommonUtils.handleTemporaryExceptions; +import static com.microsoft.applicationinsights.common.CommonUtils.lastTemporaryException; +import static com.microsoft.applicationinsights.common.CommonUtils.lastTemporaryExceptionLogger; +import static com.microsoft.applicationinsights.common.CommonUtils.lastTemporaryExceptionMessage; +import static com.microsoft.applicationinsights.common.CommonUtils.successCounter; +import static org.junit.Assert.*; + +public class NetworkExceptionsTrackerTest { + private static final ScheduledExecutorService networkIssueTrackerTest = + Executors.newSingleThreadScheduledExecutor( + ThreadPoolUtils.createDaemonThreadFactory( + NetworkExceptionsTracker.class, + "networkIssueTrackerTest")); + + @BeforeClass + public static void setUp() { + // one-time initialization code + networkIssueTrackerTest.scheduleAtFixedRate(new NetworkExceptionsTracker(), 0, 1, TimeUnit.MILLISECONDS); + } + + @After + public void tearDown() throws InterruptedException { + // cleanup code + successCounter.set(0); + failureCounter.set(0); + lastTemporaryException.set(null); + lastTemporaryExceptionLogger.set(null); + lastTemporaryExceptionMessage.set(null); + } + + @AfterClass + public static void cleanup() throws InterruptedException { + if (!networkIssueTrackerTest.isShutdown()) { + networkIssueTrackerTest.shutdown(); + } + networkIssueTrackerTest.awaitTermination(2, TimeUnit.SECONDS); + } + + + @Test + public void testSuccessAndFailureCounters() throws InterruptedException { + assertEquals(0, failureCounter.get()); + assertEquals(0, successCounter.get()); + successCounter.getAndIncrement(); + assertEquals(1, successCounter.get()); + Logger logger = LoggerFactory.getLogger(NetworkExceptionsTrackerTest.class); + Exception ex=new IllegalArgumentException(); + handleTemporaryExceptions(logger,"Test Message",ex); + assertEquals(1, failureCounter.get()); + assertEquals(ex,lastTemporaryException.get()); + assertEquals("Test Message",lastTemporaryExceptionMessage.get()); + assertEquals(logger,lastTemporaryExceptionLogger.get()); + } + + @Test + public void testFailureCountersAfterSingleFailure() throws InterruptedException { + assertEquals(0, failureCounter.get()); + assertEquals(0, successCounter.get()); + successCounter.getAndIncrement(); + failureCounter.getAndIncrement(); + assertEquals(1, successCounter.get()); + assertEquals(1, failureCounter.get()); + Logger logger = LoggerFactory.getLogger(NetworkExceptionsTrackerTest.class); + Exception ex=new IllegalArgumentException(); + handleTemporaryExceptions(logger,"Test Message",ex); + assertEquals(2, failureCounter.get()); + assertNull(lastTemporaryException.get()); + assertNull(lastTemporaryExceptionMessage.get()); + assertNull(lastTemporaryExceptionLogger.get()); + } + + @Test + public void testExceptionLogged() { + LogCaptor logCaptor = LogCaptor.forClass(NetworkExceptionsTrackerTest.class); + assertEquals(0, failureCounter.get()); + assertEquals(0, successCounter.get()); + successCounter.getAndIncrement(); + assertEquals(1, successCounter.get()); + Logger logger = LoggerFactory.getLogger(NetworkExceptionsTrackerTest.class); + Exception ex=new IllegalArgumentException(); + handleTemporaryExceptions(logger,"Test Message",ex); + assertEquals(1, failureCounter.get()); + assertEquals(ex,lastTemporaryException.get()); + assertEquals("Test Message",lastTemporaryExceptionMessage.get()); + assertEquals(logger,lastTemporaryExceptionLogger.get()); + long start = System.currentTimeMillis(); + long end = start + 3000; + while (System.currentTimeMillis() < end) { + // Wait for 3 secs, so that NetworkExceptionsTracker logs the exception + } + assertEquals(1,logCaptor.getErrorLogs().size()); + } + +} diff --git a/core/src/test/java/com/microsoft/applicationinsights/internal/util/NextworkExceptionsTrackerTest.java b/core/src/test/java/com/microsoft/applicationinsights/internal/util/NextworkExceptionsTrackerTest.java deleted file mode 100644 index 0367e37ec83..00000000000 --- a/core/src/test/java/com/microsoft/applicationinsights/internal/util/NextworkExceptionsTrackerTest.java +++ /dev/null @@ -1,77 +0,0 @@ -package com.microsoft.applicationinsights.internal.util; - -import java.util.Timer; -import java.util.TimerTask; -import java.util.concurrent.Executors; -import java.util.concurrent.ScheduledExecutorService; -import java.util.concurrent.TimeUnit; - -import org.junit.*; - -import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.failureCounter; -import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.previousFailureCounter; -import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.previousSuccessCounter; -import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.successCounter; -import static org.junit.Assert.*; - -public class NextworkExceptionsTrackerTest { - private static final ScheduledExecutorService networkIssueTrackerTest = - Executors.newSingleThreadScheduledExecutor( - ThreadPoolUtils.createDaemonThreadFactory( - NetworkExceptionsTracker.class, - "networkIssueTrackerTest")); - - @Before - public void setUp() { - // one-time initialization code - networkIssueTrackerTest.scheduleAtFixedRate(new NetworkExceptionsTracker(), 0, 1, TimeUnit.MILLISECONDS); - } - - @After - public void tearDown() throws InterruptedException { - // one-time cleanup code - if (!networkIssueTrackerTest.isShutdown()) { - networkIssueTrackerTest.shutdown(); - } - networkIssueTrackerTest.awaitTermination(2, TimeUnit.SECONDS); - } - - - @Test - public void testPreviousCountersAreAssigned() throws InterruptedException { - Timer timer = new Timer("Timer"); - TimerTask incrementFailureTask = new TimerTask() { - public void run() { - try { - failureCounter.incrementAndGet(); - Thread.sleep(0); - } catch (InterruptedException e) { - e.printStackTrace(); - } - } - }; - TimerTask incrementSuccessTask = new TimerTask() { - public void run() { - try { - Thread.sleep(0); - successCounter.incrementAndGet(); - } catch (InterruptedException e) { - e.printStackTrace(); - } - - } - }; - Thread failureThread = new Thread(incrementFailureTask); - Thread successThread = new Thread(incrementSuccessTask); - failureThread.start(); - successThread.start(); - assertEquals(0, previousFailureCounter.get()); - assertEquals(0, previousSuccessCounter.get()); - failureThread.join(); - successThread.join(); - assertEquals(1, previousFailureCounter.get()); - assertEquals(1, previousSuccessCounter.get()); - assertEquals(0, successCounter.get()); - assertEquals(0, failureCounter.get()); - } -} From d8e420cd210ed2fe7d074c0fd62e788de72c28d4 Mon Sep 17 00:00:00 2001 From: kryalama <66494519+kryalama@users.noreply.github.com> Date: Thu, 11 Feb 2021 13:06:13 -0800 Subject: [PATCH 03/18] change delay to 300 secs --- .../channel/common/ActiveTransmissionNetworkOutput.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java index 3f2f376f95b..71ae1c8dea7 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java @@ -63,7 +63,7 @@ public ActiveTransmissionNetworkOutput(TransmissionOutputSync actualOutput, Tran this.actualOutput = actualOutput; this.transmissionPolicy = transmissionPolicy; // Schedule to run every 5 minutes - this.networkIssueTracker.scheduleAtFixedRate(new NetworkExceptionsTracker(), 60,60, TimeUnit.SECONDS); + this.networkIssueTracker.scheduleAtFixedRate(new NetworkExceptionsTracker(), 300,300, TimeUnit.SECONDS); maxThreads = DEFAULT_MAX_NUMBER_OF_THREADS; outputThreads = ThreadPoolUtils.newLimitedThreadPool( From bf75fe4c65ffe119343009cc8416619e53b0d545 Mon Sep 17 00:00:00 2001 From: kryalama <66494519+kryalama@users.noreply.github.com> Date: Mon, 22 Feb 2021 10:25:24 -0800 Subject: [PATCH 04/18] adding single class 'temporaryexception' to handle network exceptions --- .../common/CommonUtils.java | 10 +-- .../customExceptions/TemporaryException.java | 71 +++++++++++++++++++ .../ActiveTransmissionNetworkOutput.java | 2 +- .../common/TransmissionNetworkOutput.java | 44 ++++++++---- .../util/NetworkExceptionsTracker.java | 28 ++++---- .../util/NetworkExceptionsTrackerTest.java | 71 +++++++------------ 6 files changed, 140 insertions(+), 86 deletions(-) create mode 100644 core/src/main/java/com/microsoft/applicationinsights/customExceptions/TemporaryException.java diff --git a/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java b/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java index eed83a02693..642454a59da 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java +++ b/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java @@ -27,6 +27,7 @@ import java.util.concurrent.atomic.AtomicLong; import java.util.concurrent.atomic.AtomicReference; +import com.microsoft.applicationinsights.customExceptions.TemporaryException; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -40,6 +41,7 @@ public class CommonUtils { public static final AtomicReference lastTemporaryException = new AtomicReference<>(); public static final AtomicReference lastTemporaryExceptionLogger = new AtomicReference<>(); public static final AtomicReference lastTemporaryExceptionMessage = new AtomicReference<>(); + public static final AtomicReference lastNetworkTemporaryException = new AtomicReference<>(); public static boolean isNullOrEmpty(String string) { @@ -80,12 +82,4 @@ public static boolean isClassPresentOnClassPath(String classSignature, ClassLoad } } - public static void handleTemporaryExceptions(Logger loggerFromException,String message, Exception ex) { - //Handle first failure - if(failureCounter.getAndIncrement() == 0) { - lastTemporaryExceptionMessage.set(message); - lastTemporaryExceptionLogger.set(loggerFromException); - lastTemporaryException.set(ex); - } - } } diff --git a/core/src/main/java/com/microsoft/applicationinsights/customExceptions/TemporaryException.java b/core/src/main/java/com/microsoft/applicationinsights/customExceptions/TemporaryException.java new file mode 100644 index 00000000000..2c32218bf14 --- /dev/null +++ b/core/src/main/java/com/microsoft/applicationinsights/customExceptions/TemporaryException.java @@ -0,0 +1,71 @@ +package com.microsoft.applicationinsights.customExceptions; +import org.slf4j.Logger; + +public class TemporaryException { + private Long successCounter; + private Long failureCounter; + private Exception lastTemporaryException; + private Logger lastTemporaryExceptionLogger; + private String lastTemporaryExceptionMessage; + + public TemporaryException() { + this.successCounter = 0L; + this.failureCounter = 0L; + } + + public TemporaryException(Long successCounter, Long failureCounter, Exception lastTemporaryException, Logger lastTemporaryExceptionLogger, String lastTemporaryExceptionMessage) { + this.successCounter = successCounter; + this.failureCounter = failureCounter; + this.lastTemporaryException = lastTemporaryException; + this.lastTemporaryExceptionLogger = lastTemporaryExceptionLogger; + this.lastTemporaryExceptionMessage = lastTemporaryExceptionMessage; + } + + public Long getSuccessCounter() { + return successCounter; + } + + public void setSuccessCounter(Long successCounter) { + this.successCounter = successCounter; + } + + public Long getFailureCounter() { + return failureCounter; + } + + public void setFailureCounter(Long failureCounter) { + this.failureCounter = failureCounter; + } + + public Exception getLastTemporaryException() { + return lastTemporaryException; + } + + public void setLastTemporaryException(Exception lastTemporaryException) { + this.lastTemporaryException = lastTemporaryException; + } + + public Logger getLastTemporaryExceptionLogger() { + return lastTemporaryExceptionLogger; + } + + public void setLastTemporaryExceptionLogger(Logger lastTemporaryExceptionLogger) { + this.lastTemporaryExceptionLogger = lastTemporaryExceptionLogger; + } + + public String getLastTemporaryExceptionMessage() { + return lastTemporaryExceptionMessage; + } + + public void setLastTemporaryExceptionMessage(String lastTemporaryExceptionMessage) { + this.lastTemporaryExceptionMessage = lastTemporaryExceptionMessage; + } + + public void incrementSuccessCounter() { + ++this.successCounter; + } + + public void incrementFailureCounter() { + ++this.failureCounter; + } +} diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java index 71ae1c8dea7..dce4da3e819 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java @@ -63,7 +63,7 @@ public ActiveTransmissionNetworkOutput(TransmissionOutputSync actualOutput, Tran this.actualOutput = actualOutput; this.transmissionPolicy = transmissionPolicy; // Schedule to run every 5 minutes - this.networkIssueTracker.scheduleAtFixedRate(new NetworkExceptionsTracker(), 300,300, TimeUnit.SECONDS); + this.networkIssueTracker.scheduleAtFixedRate(new NetworkExceptionsTracker(), 300, 300, TimeUnit.SECONDS); maxThreads = DEFAULT_MAX_NUMBER_OF_THREADS; outputThreads = ThreadPoolUtils.newLimitedThreadPool( diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java index a27a0419ca9..26d945c56f1 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java @@ -24,6 +24,7 @@ import com.google.common.base.Preconditions; import com.microsoft.applicationinsights.TelemetryConfiguration; import com.microsoft.applicationinsights.customExceptions.FriendlyException; +import com.microsoft.applicationinsights.customExceptions.TemporaryException; import com.microsoft.applicationinsights.internal.channel.TransmissionDispatcher; import com.microsoft.applicationinsights.internal.channel.TransmissionHandlerArgs; import com.microsoft.applicationinsights.internal.channel.TransmissionOutputSync; @@ -45,8 +46,7 @@ import java.net.SocketTimeoutException; import java.net.UnknownHostException; import java.util.concurrent.atomic.AtomicBoolean; -import static com.microsoft.applicationinsights.common.CommonUtils.handleTemporaryExceptions; -import static com.microsoft.applicationinsights.common.CommonUtils.successCounter; +import java.util.concurrent.atomic.AtomicReference; /** * The class is responsible for the actual sending of @@ -60,10 +60,12 @@ public final class TransmissionNetworkOutput implements TransmissionOutputSync { private static final Logger logger = LoggerFactory.getLogger(TransmissionNetworkOutput.class); private static volatile AtomicBoolean friendlyExceptionThrown = new AtomicBoolean(); + public static volatile AtomicReference temporaryNetworkException = new AtomicReference<>(new TemporaryException()); private static final String CONTENT_TYPE_HEADER = "Content-Type"; private static final String CONTENT_ENCODING_HEADER = "Content-Encoding"; private static final String RESPONSE_THROTTLING_HEADER = "Retry-After"; + private static final String TEMPORARY_EXCEPTION_MESSAGE = "Telemetry will be stored locally and re-sent later once the connection is stable again"; public static final String DEFAULT_SERVER_URI = "https://dc.services.visualstudio.com/v2/track"; @@ -177,32 +179,44 @@ public boolean sendSync(Transmission transmission) { // to be throttled transmissionPolicyManager.clearBackoff(); } - successCounter.incrementAndGet(); + + // Increment Success Counter + temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter()+1, + temporaryNetworkException.get().getFailureCounter(), + temporaryNetworkException.get().getLastTemporaryException(), + temporaryNetworkException.get().getLastTemporaryExceptionLogger(), + temporaryNetworkException.get().getLastTemporaryExceptionMessage())); return true; } catch (ConnectionPoolTimeoutException e) { - handleTemporaryExceptions(logger,"Failed to send, connection pool timeout exception. " + - "Telemetry will be stored locally and re-sent later once the connection is stable again", e); + temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), + temporaryNetworkException.get().getFailureCounter()+1, e, logger, + "Failed to send, connection pool timeout exception. "+TEMPORARY_EXCEPTION_MESSAGE)); } catch (SocketException e) { - handleTemporaryExceptions(logger,"Failed to send, socket exception. " + - "Telemetry will be stored locally and re-sent later once the connection is stable again", e); + temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), + temporaryNetworkException.get().getFailureCounter()+1, e, logger, + "Failed to send, socket exception. "+TEMPORARY_EXCEPTION_MESSAGE)); } catch (SocketTimeoutException e) { - handleTemporaryExceptions(logger,"Failed to send, socket timeout exception. " + - "Telemetry will be stored locally and re-sent later once the connection is stable again", e); + temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), + temporaryNetworkException.get().getFailureCounter()+1, e, logger, + "Failed to send, socket timeout exception. "+TEMPORARY_EXCEPTION_MESSAGE)); } catch (UnknownHostException e) { - handleTemporaryExceptions(logger,"Failed to send, wrong host address or cannot reach address due to network issues. " + - "Telemetry will be stored locally and re-sent later once the connection is stable again", e); + temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), + temporaryNetworkException.get().getFailureCounter()+1, e, logger, + "Failed to send, wrong host address or cannot reach address due to network issues. "+TEMPORARY_EXCEPTION_MESSAGE)); } catch (IOException e) { - handleTemporaryExceptions(logger,"Failed to send, IO exception. " + - "Telemetry will be stored locally and re-sent later once the connection is stable again", e); + temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), + temporaryNetworkException.get().getFailureCounter()+1, e, logger, + "Failed to send, IO exception. "+TEMPORARY_EXCEPTION_MESSAGE)); } catch (FriendlyException e) { ex = e; if(!friendlyExceptionThrown.getAndSet(true)) { logger.error(e.getMessage()); } } catch (Exception e) { - handleTemporaryExceptions(logger,"Failed to send, unexpected exception. " + - "Telemetry will be stored locally and re-sent later once the connection is stable again", e); + temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), + temporaryNetworkException.get().getFailureCounter()+1, e, logger, + "Failed to send, unexpected exception. "+TEMPORARY_EXCEPTION_MESSAGE)); } catch (ThreadDeath td) { throw td; } catch (Throwable t) { diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java b/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java index 41d6079f37e..0a7d96203a4 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java @@ -1,32 +1,28 @@ package com.microsoft.applicationinsights.internal.util; -import static com.microsoft.applicationinsights.common.CommonUtils.failureCounter; +import com.microsoft.applicationinsights.customExceptions.TemporaryException; import static com.microsoft.applicationinsights.common.CommonUtils.firstFailure; -import static com.microsoft.applicationinsights.common.CommonUtils.lastTemporaryException; -import static com.microsoft.applicationinsights.common.CommonUtils.lastTemporaryExceptionLogger; -import static com.microsoft.applicationinsights.common.CommonUtils.lastTemporaryExceptionMessage; -import static com.microsoft.applicationinsights.common.CommonUtils.successCounter; +import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.temporaryNetworkException; public class NetworkExceptionsTracker implements Runnable{ @Override public void run() { - - if(failureCounter.get() > 0 && lastTemporaryExceptionLogger.get()!=null) { + TemporaryException temporaryException = temporaryNetworkException.get(); + if(temporaryException.getFailureCounter() > 0 && temporaryException.getLastTemporaryExceptionLogger()!=null) { if(!firstFailure.getAndSet(true)) { - lastTemporaryExceptionLogger.get().error(lastTemporaryExceptionMessage.get()+"\n"+ - "Total number of successful telemetry requests so far:"+successCounter.get()+"\n"+ + temporaryException.getLastTemporaryExceptionLogger().error(temporaryException.getLastTemporaryExceptionMessage()+"\n"+ + "Total number of successful telemetry requests so far:"+temporaryException.getSuccessCounter()+"\n"+ "Future failures will be aggregated and logged once every 5 minutes\n", - lastTemporaryException.get() + temporaryException.getLastTemporaryException() ); } else { - lastTemporaryExceptionLogger.get().error(lastTemporaryExceptionMessage.get()+"\n"+ - "Total number of failed telemetry requests in the last 5 minutes:"+failureCounter.get()+"\n"+ - "Total number of successful telemetry requests in the last 5 minutes:"+successCounter.get()+"\n"+ - lastTemporaryException.get() + temporaryException.getLastTemporaryExceptionLogger().error(temporaryException.getLastTemporaryExceptionMessage()+"\n"+ + "Total number of failed telemetry requests in the last 5 minutes:"+temporaryException.getFailureCounter()+"\n"+ + "Total number of successful telemetry requests in the last 5 minutes:"+temporaryException.getSuccessCounter()+"\n"+ + temporaryException.getLastTemporaryException() ); } - failureCounter.set(0); - successCounter.set(0); + temporaryNetworkException.set(new TemporaryException()); } } } diff --git a/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java b/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java index 4f82609c950..09df0010f79 100644 --- a/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java +++ b/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java @@ -4,17 +4,13 @@ import java.util.concurrent.ScheduledExecutorService; import java.util.concurrent.TimeUnit; +import com.microsoft.applicationinsights.customExceptions.TemporaryException; import nl.altindag.log.LogCaptor; import org.junit.*; import org.slf4j.Logger; import org.slf4j.LoggerFactory; -import static com.microsoft.applicationinsights.common.CommonUtils.failureCounter; -import static com.microsoft.applicationinsights.common.CommonUtils.handleTemporaryExceptions; -import static com.microsoft.applicationinsights.common.CommonUtils.lastTemporaryException; -import static com.microsoft.applicationinsights.common.CommonUtils.lastTemporaryExceptionLogger; -import static com.microsoft.applicationinsights.common.CommonUtils.lastTemporaryExceptionMessage; -import static com.microsoft.applicationinsights.common.CommonUtils.successCounter; +import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.temporaryNetworkException; import static org.junit.Assert.*; public class NetworkExceptionsTrackerTest { @@ -33,11 +29,7 @@ public static void setUp() { @After public void tearDown() throws InterruptedException { // cleanup code - successCounter.set(0); - failureCounter.set(0); - lastTemporaryException.set(null); - lastTemporaryExceptionLogger.set(null); - lastTemporaryExceptionMessage.set(null); + temporaryNetworkException.set(new TemporaryException()); } @AfterClass @@ -51,50 +43,37 @@ public static void cleanup() throws InterruptedException { @Test public void testSuccessAndFailureCounters() throws InterruptedException { - assertEquals(0, failureCounter.get()); - assertEquals(0, successCounter.get()); - successCounter.getAndIncrement(); - assertEquals(1, successCounter.get()); + TemporaryException temporaryException = temporaryNetworkException.get(); + assertEquals(java.util.Optional.of(0L), java.util.Optional.ofNullable(temporaryException.getFailureCounter())); + assertEquals(java.util.Optional.of(0L), java.util.Optional.ofNullable(temporaryException.getSuccessCounter())); + temporaryException.incrementSuccessCounter(); + assertEquals(java.util.Optional.of(1L), java.util.Optional.ofNullable(temporaryException.getSuccessCounter())); Logger logger = LoggerFactory.getLogger(NetworkExceptionsTrackerTest.class); Exception ex=new IllegalArgumentException(); - handleTemporaryExceptions(logger,"Test Message",ex); - assertEquals(1, failureCounter.get()); - assertEquals(ex,lastTemporaryException.get()); - assertEquals("Test Message",lastTemporaryExceptionMessage.get()); - assertEquals(logger,lastTemporaryExceptionLogger.get()); - } - - @Test - public void testFailureCountersAfterSingleFailure() throws InterruptedException { - assertEquals(0, failureCounter.get()); - assertEquals(0, successCounter.get()); - successCounter.getAndIncrement(); - failureCounter.getAndIncrement(); - assertEquals(1, successCounter.get()); - assertEquals(1, failureCounter.get()); - Logger logger = LoggerFactory.getLogger(NetworkExceptionsTrackerTest.class); - Exception ex=new IllegalArgumentException(); - handleTemporaryExceptions(logger,"Test Message",ex); - assertEquals(2, failureCounter.get()); - assertNull(lastTemporaryException.get()); - assertNull(lastTemporaryExceptionMessage.get()); - assertNull(lastTemporaryExceptionLogger.get()); + temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), + temporaryNetworkException.get().getFailureCounter()+1, ex, logger, "Test Message")); + assertEquals(java.util.Optional.of(1L), java.util.Optional.ofNullable(temporaryNetworkException.get().getFailureCounter())); + assertEquals(ex,temporaryNetworkException.get().getLastTemporaryException()); + assertEquals("Test Message",temporaryNetworkException.get().getLastTemporaryExceptionMessage()); + assertEquals(logger,temporaryNetworkException.get().getLastTemporaryExceptionLogger()); } @Test public void testExceptionLogged() { LogCaptor logCaptor = LogCaptor.forClass(NetworkExceptionsTrackerTest.class); - assertEquals(0, failureCounter.get()); - assertEquals(0, successCounter.get()); - successCounter.getAndIncrement(); - assertEquals(1, successCounter.get()); + TemporaryException temporaryException = temporaryNetworkException.get(); + assertEquals(java.util.Optional.of(0L), java.util.Optional.ofNullable(temporaryException.getFailureCounter())); + assertEquals(java.util.Optional.of(0L), java.util.Optional.ofNullable(temporaryException.getSuccessCounter())); + temporaryException.incrementSuccessCounter(); + assertEquals(java.util.Optional.of(1L), java.util.Optional.ofNullable(temporaryException.getSuccessCounter())); Logger logger = LoggerFactory.getLogger(NetworkExceptionsTrackerTest.class); Exception ex=new IllegalArgumentException(); - handleTemporaryExceptions(logger,"Test Message",ex); - assertEquals(1, failureCounter.get()); - assertEquals(ex,lastTemporaryException.get()); - assertEquals("Test Message",lastTemporaryExceptionMessage.get()); - assertEquals(logger,lastTemporaryExceptionLogger.get()); + temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), + temporaryNetworkException.get().getFailureCounter()+1, ex, logger, "Test Message")); + assertEquals(java.util.Optional.of(1L), java.util.Optional.ofNullable(temporaryNetworkException.get().getFailureCounter())); + assertEquals(ex,temporaryNetworkException.get().getLastTemporaryException()); + assertEquals("Test Message",temporaryNetworkException.get().getLastTemporaryExceptionMessage()); + assertEquals(logger,temporaryNetworkException.get().getLastTemporaryExceptionLogger()); long start = System.currentTimeMillis(); long end = start + 3000; while (System.currentTimeMillis() < end) { From 9277536acdfffc2baf9b0f62cbbff44bd0966061 Mon Sep 17 00:00:00 2001 From: kryalama <66494519+kryalama@users.noreply.github.com> Date: Mon, 22 Feb 2021 10:42:29 -0800 Subject: [PATCH 05/18] remove unused Atomic references --- .../microsoft/applicationinsights/common/CommonUtils.java | 8 -------- .../channel/common/TransmissionNetworkOutput.java | 1 + .../internal/util/NetworkExceptionsTracker.java | 3 ++- 3 files changed, 3 insertions(+), 9 deletions(-) diff --git a/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java b/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java index 642454a59da..a753864704c 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java +++ b/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java @@ -35,14 +35,6 @@ public class CommonUtils { private static final Logger logger = LoggerFactory.getLogger(CommonUtils.class); - public static final AtomicLong successCounter = new AtomicLong(0); - public static final AtomicLong failureCounter = new AtomicLong(0); - public static final AtomicBoolean firstFailure = new AtomicBoolean(false); - public static final AtomicReference lastTemporaryException = new AtomicReference<>(); - public static final AtomicReference lastTemporaryExceptionLogger = new AtomicReference<>(); - public static final AtomicReference lastTemporaryExceptionMessage = new AtomicReference<>(); - public static final AtomicReference lastNetworkTemporaryException = new AtomicReference<>(); - public static boolean isNullOrEmpty(String string) { return string == null || string.length() == 0; diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java index 26d945c56f1..a21285ff5d9 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java @@ -60,6 +60,7 @@ public final class TransmissionNetworkOutput implements TransmissionOutputSync { private static final Logger logger = LoggerFactory.getLogger(TransmissionNetworkOutput.class); private static volatile AtomicBoolean friendlyExceptionThrown = new AtomicBoolean(); + public static final AtomicBoolean firstFailure = new AtomicBoolean(false); public static volatile AtomicReference temporaryNetworkException = new AtomicReference<>(new TemporaryException()); private static final String CONTENT_TYPE_HEADER = "Content-Type"; diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java b/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java index 0a7d96203a4..b02183b01eb 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java @@ -2,7 +2,8 @@ import com.microsoft.applicationinsights.customExceptions.TemporaryException; -import static com.microsoft.applicationinsights.common.CommonUtils.firstFailure; + +import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.firstFailure; import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.temporaryNetworkException; public class NetworkExceptionsTracker implements Runnable{ From bc63adba7f8414e60582ea84aaa71d8124f906e9 Mon Sep 17 00:00:00 2001 From: kryalama <66494519+kryalama@users.noreply.github.com> Date: Mon, 22 Feb 2021 11:05:28 -0800 Subject: [PATCH 06/18] Fixed bug with previous commit where exception message is being updated on every exception --- .../common/TransmissionNetworkOutput.java | 39 ++++++++++--------- 1 file changed, 21 insertions(+), 18 deletions(-) diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java index a21285ff5d9..6f28dc4a5e5 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java @@ -190,34 +190,22 @@ public boolean sendSync(Transmission transmission) { return true; } catch (ConnectionPoolTimeoutException e) { - temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), - temporaryNetworkException.get().getFailureCounter()+1, e, logger, - "Failed to send, connection pool timeout exception. "+TEMPORARY_EXCEPTION_MESSAGE)); + handleTemporaryException("Failed to send, connection pool timeout exception. ", logger, e); } catch (SocketException e) { - temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), - temporaryNetworkException.get().getFailureCounter()+1, e, logger, - "Failed to send, socket exception. "+TEMPORARY_EXCEPTION_MESSAGE)); + handleTemporaryException("Failed to send, socket exception. ", logger, e); } catch (SocketTimeoutException e) { - temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), - temporaryNetworkException.get().getFailureCounter()+1, e, logger, - "Failed to send, socket timeout exception. "+TEMPORARY_EXCEPTION_MESSAGE)); + handleTemporaryException("Failed to send, socket timeout exception. ", logger, e); } catch (UnknownHostException e) { - temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), - temporaryNetworkException.get().getFailureCounter()+1, e, logger, - "Failed to send, wrong host address or cannot reach address due to network issues. "+TEMPORARY_EXCEPTION_MESSAGE)); + handleTemporaryException("Failed to send, wrong host address or cannot reach address due to network issues. ", logger, e); } catch (IOException e) { - temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), - temporaryNetworkException.get().getFailureCounter()+1, e, logger, - "Failed to send, IO exception. "+TEMPORARY_EXCEPTION_MESSAGE)); + handleTemporaryException("Failed to send, IO exception. ", logger, e); } catch (FriendlyException e) { ex = e; if(!friendlyExceptionThrown.getAndSet(true)) { logger.error(e.getMessage()); } } catch (Exception e) { - temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), - temporaryNetworkException.get().getFailureCounter()+1, e, logger, - "Failed to send, unexpected exception. "+TEMPORARY_EXCEPTION_MESSAGE)); + handleTemporaryException("Failed to send, unexpected exception. ", logger, e); } catch (ThreadDeath td) { throw td; } catch (Throwable t) { @@ -259,6 +247,21 @@ public boolean sendSync(Transmission transmission) { return true; } + private static void handleTemporaryException(String message, Logger logger, Exception ex) { + if(temporaryNetworkException.get().getFailureCounter() == 0) { + temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), + temporaryNetworkException.get().getFailureCounter()+1, ex, logger, + message+TEMPORARY_EXCEPTION_MESSAGE)); + } else { + temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), + temporaryNetworkException.get().getFailureCounter()+1, + temporaryNetworkException.get().getLastTemporaryException(), + temporaryNetworkException.get().getLastTemporaryExceptionLogger(), + temporaryNetworkException.get().getLastTemporaryExceptionMessage())); + } + + } + /** * Generates the HTTP POST to send to the endpoint. * From 2e1dba192c9c2384ee6e691fb4f739cd91b6cf66 Mon Sep 17 00:00:00 2001 From: kryalama <66494519+kryalama@users.noreply.github.com> Date: Mon, 22 Feb 2021 13:04:58 -0800 Subject: [PATCH 07/18] fix spotbugs issues --- .../common/CommonUtils.java | 4 --- .../common/TransmissionNetworkOutput.java | 10 +++---- .../util/NetworkExceptionsTracker.java | 22 +++++++-------- .../util/TemporaryExceptionWrapper.java} | 8 +++--- .../util/NetworkExceptionsTrackerTest.java | 27 +++++++++---------- 5 files changed, 32 insertions(+), 39 deletions(-) rename core/src/main/java/com/microsoft/applicationinsights/{customExceptions/TemporaryException.java => internal/util/TemporaryExceptionWrapper.java} (85%) diff --git a/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java b/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java index a753864704c..dbb1453312d 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java +++ b/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java @@ -23,11 +23,7 @@ import java.net.InetAddress; import java.net.UnknownHostException; -import java.util.concurrent.atomic.AtomicBoolean; -import java.util.concurrent.atomic.AtomicLong; -import java.util.concurrent.atomic.AtomicReference; -import com.microsoft.applicationinsights.customExceptions.TemporaryException; import org.slf4j.Logger; import org.slf4j.LoggerFactory; diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java index 6f28dc4a5e5..b0ef6d3349e 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java @@ -24,7 +24,7 @@ import com.google.common.base.Preconditions; import com.microsoft.applicationinsights.TelemetryConfiguration; import com.microsoft.applicationinsights.customExceptions.FriendlyException; -import com.microsoft.applicationinsights.customExceptions.TemporaryException; +import com.microsoft.applicationinsights.internal.util.TemporaryExceptionWrapper; import com.microsoft.applicationinsights.internal.channel.TransmissionDispatcher; import com.microsoft.applicationinsights.internal.channel.TransmissionHandlerArgs; import com.microsoft.applicationinsights.internal.channel.TransmissionOutputSync; @@ -61,7 +61,7 @@ public final class TransmissionNetworkOutput implements TransmissionOutputSync { private static final Logger logger = LoggerFactory.getLogger(TransmissionNetworkOutput.class); private static volatile AtomicBoolean friendlyExceptionThrown = new AtomicBoolean(); public static final AtomicBoolean firstFailure = new AtomicBoolean(false); - public static volatile AtomicReference temporaryNetworkException = new AtomicReference<>(new TemporaryException()); + public static volatile AtomicReference temporaryNetworkException = new AtomicReference<>(new TemporaryExceptionWrapper()); private static final String CONTENT_TYPE_HEADER = "Content-Type"; private static final String CONTENT_ENCODING_HEADER = "Content-Encoding"; @@ -182,7 +182,7 @@ public boolean sendSync(Transmission transmission) { } // Increment Success Counter - temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter()+1, + temporaryNetworkException.set(new TemporaryExceptionWrapper(temporaryNetworkException.get().getSuccessCounter()+1, temporaryNetworkException.get().getFailureCounter(), temporaryNetworkException.get().getLastTemporaryException(), temporaryNetworkException.get().getLastTemporaryExceptionLogger(), @@ -249,11 +249,11 @@ public boolean sendSync(Transmission transmission) { private static void handleTemporaryException(String message, Logger logger, Exception ex) { if(temporaryNetworkException.get().getFailureCounter() == 0) { - temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), + temporaryNetworkException.set(new TemporaryExceptionWrapper(temporaryNetworkException.get().getSuccessCounter(), temporaryNetworkException.get().getFailureCounter()+1, ex, logger, message+TEMPORARY_EXCEPTION_MESSAGE)); } else { - temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), + temporaryNetworkException.set(new TemporaryExceptionWrapper(temporaryNetworkException.get().getSuccessCounter(), temporaryNetworkException.get().getFailureCounter()+1, temporaryNetworkException.get().getLastTemporaryException(), temporaryNetworkException.get().getLastTemporaryExceptionLogger(), diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java b/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java index b02183b01eb..ba758c18634 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java @@ -1,29 +1,27 @@ package com.microsoft.applicationinsights.internal.util; -import com.microsoft.applicationinsights.customExceptions.TemporaryException; - import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.firstFailure; import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.temporaryNetworkException; public class NetworkExceptionsTracker implements Runnable{ @Override public void run() { - TemporaryException temporaryException = temporaryNetworkException.get(); - if(temporaryException.getFailureCounter() > 0 && temporaryException.getLastTemporaryExceptionLogger()!=null) { + TemporaryExceptionWrapper temporaryExceptionWrapper = temporaryNetworkException.get(); + if(temporaryExceptionWrapper.getFailureCounter() > 0 && temporaryExceptionWrapper.getLastTemporaryExceptionLogger()!=null) { if(!firstFailure.getAndSet(true)) { - temporaryException.getLastTemporaryExceptionLogger().error(temporaryException.getLastTemporaryExceptionMessage()+"\n"+ - "Total number of successful telemetry requests so far:"+temporaryException.getSuccessCounter()+"\n"+ + temporaryExceptionWrapper.getLastTemporaryExceptionLogger().error(temporaryExceptionWrapper.getLastTemporaryExceptionMessage()+"\n"+ + "Total number of successful telemetry requests so far:"+ temporaryExceptionWrapper.getSuccessCounter()+"\n"+ "Future failures will be aggregated and logged once every 5 minutes\n", - temporaryException.getLastTemporaryException() + temporaryExceptionWrapper.getLastTemporaryException() ); } else { - temporaryException.getLastTemporaryExceptionLogger().error(temporaryException.getLastTemporaryExceptionMessage()+"\n"+ - "Total number of failed telemetry requests in the last 5 minutes:"+temporaryException.getFailureCounter()+"\n"+ - "Total number of successful telemetry requests in the last 5 minutes:"+temporaryException.getSuccessCounter()+"\n"+ - temporaryException.getLastTemporaryException() + temporaryExceptionWrapper.getLastTemporaryExceptionLogger().error(temporaryExceptionWrapper.getLastTemporaryExceptionMessage()+"\n"+ + "Total number of failed telemetry requests in the last 5 minutes:"+ temporaryExceptionWrapper.getFailureCounter()+"\n"+ + "Total number of successful telemetry requests in the last 5 minutes:"+ temporaryExceptionWrapper.getSuccessCounter()+"\n"+ + temporaryExceptionWrapper.getLastTemporaryException() ); } - temporaryNetworkException.set(new TemporaryException()); + temporaryNetworkException.set(new TemporaryExceptionWrapper()); } } } diff --git a/core/src/main/java/com/microsoft/applicationinsights/customExceptions/TemporaryException.java b/core/src/main/java/com/microsoft/applicationinsights/internal/util/TemporaryExceptionWrapper.java similarity index 85% rename from core/src/main/java/com/microsoft/applicationinsights/customExceptions/TemporaryException.java rename to core/src/main/java/com/microsoft/applicationinsights/internal/util/TemporaryExceptionWrapper.java index 2c32218bf14..4c3e7f33f66 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/customExceptions/TemporaryException.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/util/TemporaryExceptionWrapper.java @@ -1,19 +1,19 @@ -package com.microsoft.applicationinsights.customExceptions; +package com.microsoft.applicationinsights.internal.util; import org.slf4j.Logger; -public class TemporaryException { +public class TemporaryExceptionWrapper { private Long successCounter; private Long failureCounter; private Exception lastTemporaryException; private Logger lastTemporaryExceptionLogger; private String lastTemporaryExceptionMessage; - public TemporaryException() { + public TemporaryExceptionWrapper() { this.successCounter = 0L; this.failureCounter = 0L; } - public TemporaryException(Long successCounter, Long failureCounter, Exception lastTemporaryException, Logger lastTemporaryExceptionLogger, String lastTemporaryExceptionMessage) { + public TemporaryExceptionWrapper(Long successCounter, Long failureCounter, Exception lastTemporaryException, Logger lastTemporaryExceptionLogger, String lastTemporaryExceptionMessage) { this.successCounter = successCounter; this.failureCounter = failureCounter; this.lastTemporaryException = lastTemporaryException; diff --git a/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java b/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java index 09df0010f79..2073b9ddfcc 100644 --- a/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java +++ b/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java @@ -4,7 +4,6 @@ import java.util.concurrent.ScheduledExecutorService; import java.util.concurrent.TimeUnit; -import com.microsoft.applicationinsights.customExceptions.TemporaryException; import nl.altindag.log.LogCaptor; import org.junit.*; import org.slf4j.Logger; @@ -29,7 +28,7 @@ public static void setUp() { @After public void tearDown() throws InterruptedException { // cleanup code - temporaryNetworkException.set(new TemporaryException()); + temporaryNetworkException.set(new TemporaryExceptionWrapper()); } @AfterClass @@ -43,14 +42,14 @@ public static void cleanup() throws InterruptedException { @Test public void testSuccessAndFailureCounters() throws InterruptedException { - TemporaryException temporaryException = temporaryNetworkException.get(); - assertEquals(java.util.Optional.of(0L), java.util.Optional.ofNullable(temporaryException.getFailureCounter())); - assertEquals(java.util.Optional.of(0L), java.util.Optional.ofNullable(temporaryException.getSuccessCounter())); - temporaryException.incrementSuccessCounter(); - assertEquals(java.util.Optional.of(1L), java.util.Optional.ofNullable(temporaryException.getSuccessCounter())); + TemporaryExceptionWrapper temporaryExceptionWrapper = temporaryNetworkException.get(); + assertEquals(java.util.Optional.of(0L), java.util.Optional.ofNullable(temporaryExceptionWrapper.getFailureCounter())); + assertEquals(java.util.Optional.of(0L), java.util.Optional.ofNullable(temporaryExceptionWrapper.getSuccessCounter())); + temporaryExceptionWrapper.incrementSuccessCounter(); + assertEquals(java.util.Optional.of(1L), java.util.Optional.ofNullable(temporaryExceptionWrapper.getSuccessCounter())); Logger logger = LoggerFactory.getLogger(NetworkExceptionsTrackerTest.class); Exception ex=new IllegalArgumentException(); - temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), + temporaryNetworkException.set(new TemporaryExceptionWrapper(temporaryNetworkException.get().getSuccessCounter(), temporaryNetworkException.get().getFailureCounter()+1, ex, logger, "Test Message")); assertEquals(java.util.Optional.of(1L), java.util.Optional.ofNullable(temporaryNetworkException.get().getFailureCounter())); assertEquals(ex,temporaryNetworkException.get().getLastTemporaryException()); @@ -61,14 +60,14 @@ public void testSuccessAndFailureCounters() throws InterruptedException { @Test public void testExceptionLogged() { LogCaptor logCaptor = LogCaptor.forClass(NetworkExceptionsTrackerTest.class); - TemporaryException temporaryException = temporaryNetworkException.get(); - assertEquals(java.util.Optional.of(0L), java.util.Optional.ofNullable(temporaryException.getFailureCounter())); - assertEquals(java.util.Optional.of(0L), java.util.Optional.ofNullable(temporaryException.getSuccessCounter())); - temporaryException.incrementSuccessCounter(); - assertEquals(java.util.Optional.of(1L), java.util.Optional.ofNullable(temporaryException.getSuccessCounter())); + TemporaryExceptionWrapper temporaryExceptionWrapper = temporaryNetworkException.get(); + assertEquals(java.util.Optional.of(0L), java.util.Optional.ofNullable(temporaryExceptionWrapper.getFailureCounter())); + assertEquals(java.util.Optional.of(0L), java.util.Optional.ofNullable(temporaryExceptionWrapper.getSuccessCounter())); + temporaryExceptionWrapper.incrementSuccessCounter(); + assertEquals(java.util.Optional.of(1L), java.util.Optional.ofNullable(temporaryExceptionWrapper.getSuccessCounter())); Logger logger = LoggerFactory.getLogger(NetworkExceptionsTrackerTest.class); Exception ex=new IllegalArgumentException(); - temporaryNetworkException.set(new TemporaryException(temporaryNetworkException.get().getSuccessCounter(), + temporaryNetworkException.set(new TemporaryExceptionWrapper(temporaryNetworkException.get().getSuccessCounter(), temporaryNetworkException.get().getFailureCounter()+1, ex, logger, "Test Message")); assertEquals(java.util.Optional.of(1L), java.util.Optional.ofNullable(temporaryNetworkException.get().getFailureCounter())); assertEquals(ex,temporaryNetworkException.get().getLastTemporaryException()); From 347be1c0af832e8458aa120050d4e57e11665564 Mon Sep 17 00:00:00 2001 From: kryalama <66494519+kryalama@users.noreply.github.com> Date: Tue, 23 Feb 2021 10:09:53 -0800 Subject: [PATCH 08/18] first error message will be logged as soon as it is thrown --- .../common/TransmissionNetworkOutput.java | 7 ++++ .../util/NetworkExceptionsTracker.java | 18 +++-------- .../util/TemporaryExceptionWrapper.java | 32 ++++--------------- .../util/NetworkExceptionsTrackerTest.java | 25 +++++++-------- .../smoketest/SpringCloudStreamTest.java | 5 +-- 5 files changed, 32 insertions(+), 55 deletions(-) diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java index b0ef6d3349e..2c9abfcb037 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java @@ -248,6 +248,13 @@ public boolean sendSync(Transmission transmission) { } private static void handleTemporaryException(String message, Logger logger, Exception ex) { + // We log the first exception as soon as it is thrown + if(!firstFailure.getAndSet(true)) { + logger.error(message+"\n"+ + "Total number of successful telemetry requests so far:"+ temporaryNetworkException.get().getSuccessCounter()+"\n"+ + "Future failures will be aggregated and logged once every 5 minutes\n", ex); + } + if(temporaryNetworkException.get().getFailureCounter() == 0) { temporaryNetworkException.set(new TemporaryExceptionWrapper(temporaryNetworkException.get().getSuccessCounter(), temporaryNetworkException.get().getFailureCounter()+1, ex, logger, diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java b/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java index ba758c18634..b85cd23536d 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java @@ -1,27 +1,17 @@ package com.microsoft.applicationinsights.internal.util; - -import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.firstFailure; import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.temporaryNetworkException; public class NetworkExceptionsTracker implements Runnable{ @Override public void run() { TemporaryExceptionWrapper temporaryExceptionWrapper = temporaryNetworkException.get(); if(temporaryExceptionWrapper.getFailureCounter() > 0 && temporaryExceptionWrapper.getLastTemporaryExceptionLogger()!=null) { - if(!firstFailure.getAndSet(true)) { - temporaryExceptionWrapper.getLastTemporaryExceptionLogger().error(temporaryExceptionWrapper.getLastTemporaryExceptionMessage()+"\n"+ - "Total number of successful telemetry requests so far:"+ temporaryExceptionWrapper.getSuccessCounter()+"\n"+ - "Future failures will be aggregated and logged once every 5 minutes\n", - temporaryExceptionWrapper.getLastTemporaryException() - ); - } else { - temporaryExceptionWrapper.getLastTemporaryExceptionLogger().error(temporaryExceptionWrapper.getLastTemporaryExceptionMessage()+"\n"+ + temporaryExceptionWrapper.getLastTemporaryExceptionLogger().error(temporaryExceptionWrapper.getLastTemporaryExceptionMessage()+"\n"+ "Total number of failed telemetry requests in the last 5 minutes:"+ temporaryExceptionWrapper.getFailureCounter()+"\n"+ - "Total number of successful telemetry requests in the last 5 minutes:"+ temporaryExceptionWrapper.getSuccessCounter()+"\n"+ + "Total number of successful telemetry requests in the last 5 minutes:"+ temporaryExceptionWrapper.getSuccessCounter()+"\n", temporaryExceptionWrapper.getLastTemporaryException() - ); - } - temporaryNetworkException.set(new TemporaryExceptionWrapper()); + ); } + temporaryNetworkException.set(new TemporaryExceptionWrapper()); } } diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/util/TemporaryExceptionWrapper.java b/core/src/main/java/com/microsoft/applicationinsights/internal/util/TemporaryExceptionWrapper.java index 4c3e7f33f66..34588fd5429 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/util/TemporaryExceptionWrapper.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/util/TemporaryExceptionWrapper.java @@ -2,8 +2,8 @@ import org.slf4j.Logger; public class TemporaryExceptionWrapper { - private Long successCounter; - private Long failureCounter; + private long successCounter; + private long failureCounter; private Exception lastTemporaryException; private Logger lastTemporaryExceptionLogger; private String lastTemporaryExceptionMessage; @@ -13,7 +13,7 @@ public TemporaryExceptionWrapper() { this.failureCounter = 0L; } - public TemporaryExceptionWrapper(Long successCounter, Long failureCounter, Exception lastTemporaryException, Logger lastTemporaryExceptionLogger, String lastTemporaryExceptionMessage) { + public TemporaryExceptionWrapper(long successCounter, long failureCounter, Exception lastTemporaryException, Logger lastTemporaryExceptionLogger, String lastTemporaryExceptionMessage) { this.successCounter = successCounter; this.failureCounter = failureCounter; this.lastTemporaryException = lastTemporaryException; @@ -21,50 +21,32 @@ public TemporaryExceptionWrapper(Long successCounter, Long failureCounter, Excep this.lastTemporaryExceptionMessage = lastTemporaryExceptionMessage; } - public Long getSuccessCounter() { + public long getSuccessCounter() { return successCounter; } - public void setSuccessCounter(Long successCounter) { - this.successCounter = successCounter; - } - - public Long getFailureCounter() { + public long getFailureCounter() { return failureCounter; } - public void setFailureCounter(Long failureCounter) { - this.failureCounter = failureCounter; - } - public Exception getLastTemporaryException() { return lastTemporaryException; } - public void setLastTemporaryException(Exception lastTemporaryException) { - this.lastTemporaryException = lastTemporaryException; - } - public Logger getLastTemporaryExceptionLogger() { return lastTemporaryExceptionLogger; } - public void setLastTemporaryExceptionLogger(Logger lastTemporaryExceptionLogger) { - this.lastTemporaryExceptionLogger = lastTemporaryExceptionLogger; - } - public String getLastTemporaryExceptionMessage() { return lastTemporaryExceptionMessage; } - public void setLastTemporaryExceptionMessage(String lastTemporaryExceptionMessage) { - this.lastTemporaryExceptionMessage = lastTemporaryExceptionMessage; - } - + // only used in tests public void incrementSuccessCounter() { ++this.successCounter; } + //only used in tests public void incrementFailureCounter() { ++this.failureCounter; } diff --git a/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java b/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java index 2073b9ddfcc..e805ecc8640 100644 --- a/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java +++ b/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java @@ -43,41 +43,38 @@ public static void cleanup() throws InterruptedException { @Test public void testSuccessAndFailureCounters() throws InterruptedException { TemporaryExceptionWrapper temporaryExceptionWrapper = temporaryNetworkException.get(); - assertEquals(java.util.Optional.of(0L), java.util.Optional.ofNullable(temporaryExceptionWrapper.getFailureCounter())); - assertEquals(java.util.Optional.of(0L), java.util.Optional.ofNullable(temporaryExceptionWrapper.getSuccessCounter())); + assertEquals(0L, temporaryExceptionWrapper.getFailureCounter()); + assertEquals(0L, temporaryExceptionWrapper.getSuccessCounter()); temporaryExceptionWrapper.incrementSuccessCounter(); - assertEquals(java.util.Optional.of(1L), java.util.Optional.ofNullable(temporaryExceptionWrapper.getSuccessCounter())); + assertEquals(1L, temporaryExceptionWrapper.getSuccessCounter()); Logger logger = LoggerFactory.getLogger(NetworkExceptionsTrackerTest.class); Exception ex=new IllegalArgumentException(); temporaryNetworkException.set(new TemporaryExceptionWrapper(temporaryNetworkException.get().getSuccessCounter(), temporaryNetworkException.get().getFailureCounter()+1, ex, logger, "Test Message")); - assertEquals(java.util.Optional.of(1L), java.util.Optional.ofNullable(temporaryNetworkException.get().getFailureCounter())); + assertEquals(1L, temporaryNetworkException.get().getFailureCounter()); assertEquals(ex,temporaryNetworkException.get().getLastTemporaryException()); assertEquals("Test Message",temporaryNetworkException.get().getLastTemporaryExceptionMessage()); assertEquals(logger,temporaryNetworkException.get().getLastTemporaryExceptionLogger()); } @Test - public void testExceptionLogged() { + public void testExceptionLogged() throws InterruptedException { LogCaptor logCaptor = LogCaptor.forClass(NetworkExceptionsTrackerTest.class); TemporaryExceptionWrapper temporaryExceptionWrapper = temporaryNetworkException.get(); - assertEquals(java.util.Optional.of(0L), java.util.Optional.ofNullable(temporaryExceptionWrapper.getFailureCounter())); - assertEquals(java.util.Optional.of(0L), java.util.Optional.ofNullable(temporaryExceptionWrapper.getSuccessCounter())); + assertEquals(0L, temporaryExceptionWrapper.getFailureCounter()); + assertEquals(0L, temporaryExceptionWrapper.getSuccessCounter()); temporaryExceptionWrapper.incrementSuccessCounter(); - assertEquals(java.util.Optional.of(1L), java.util.Optional.ofNullable(temporaryExceptionWrapper.getSuccessCounter())); + assertEquals(1L, temporaryExceptionWrapper.getSuccessCounter()); Logger logger = LoggerFactory.getLogger(NetworkExceptionsTrackerTest.class); Exception ex=new IllegalArgumentException(); temporaryNetworkException.set(new TemporaryExceptionWrapper(temporaryNetworkException.get().getSuccessCounter(), temporaryNetworkException.get().getFailureCounter()+1, ex, logger, "Test Message")); - assertEquals(java.util.Optional.of(1L), java.util.Optional.ofNullable(temporaryNetworkException.get().getFailureCounter())); + assertEquals(1L, temporaryNetworkException.get().getFailureCounter()); assertEquals(ex,temporaryNetworkException.get().getLastTemporaryException()); assertEquals("Test Message",temporaryNetworkException.get().getLastTemporaryExceptionMessage()); assertEquals(logger,temporaryNetworkException.get().getLastTemporaryExceptionLogger()); - long start = System.currentTimeMillis(); - long end = start + 3000; - while (System.currentTimeMillis() < end) { - // Wait for 3 secs, so that NetworkExceptionsTracker logs the exception - } + //wait for 3 secs + Thread.sleep(3000); assertEquals(1,logCaptor.getErrorLogs().size()); } diff --git a/test/smoke/testApps/SpringCloudStream/src/smokeTest/java/com/microsoft/applicationinsights/smoketest/SpringCloudStreamTest.java b/test/smoke/testApps/SpringCloudStream/src/smokeTest/java/com/microsoft/applicationinsights/smoketest/SpringCloudStreamTest.java index ef2f889ea37..43ccfacde34 100644 --- a/test/smoke/testApps/SpringCloudStream/src/smokeTest/java/com/microsoft/applicationinsights/smoketest/SpringCloudStreamTest.java +++ b/test/smoke/testApps/SpringCloudStream/src/smokeTest/java/com/microsoft/applicationinsights/smoketest/SpringCloudStreamTest.java @@ -59,8 +59,9 @@ public void doMostBasicTest() throws Exception { assertEquals("greetings", rd2.getSource()); assertEquals("greetings process", rd2.getName()); - assertParentChild(rdd1.getId(), rdEnvelope1, rddEnvelope2); - assertParentChild(rdd2.getId(), rddEnvelope1, rdEnvelope2); + assertParentChild(rd1.getId(), rdEnvelope1, rddEnvelope1); + assertParentChild(rdd1.getId(), rddEnvelope1, rddEnvelope2); + assertParentChild(rdd2.getId(), rddEnvelope2, rdEnvelope2); } private static void assertParentChild(String parentId, Envelope parentEnvelope, Envelope childEnvelope) { From e17c699d6ef8f473410be0da44597fd62f80f2c0 Mon Sep 17 00:00:00 2001 From: Trask Stalnaker Date: Tue, 23 Feb 2021 11:12:26 -0800 Subject: [PATCH 09/18] Encapsulate the new feature a bit more --- .../ActiveTransmissionNetworkOutput.java | 8 -- .../common/TransmissionNetworkOutput.java | 68 ++++++---------- .../internal/util/ExceptionStats.java | 81 +++++++++++++++++++ .../util/NetworkExceptionsTracker.java | 17 ---- .../util/TemporaryExceptionWrapper.java | 53 ------------ .../util/ExceptionStatsLoggerTest.java | 81 +++++++++++++++++++ .../util/NetworkExceptionsTrackerTest.java | 81 ------------------- 7 files changed, 185 insertions(+), 204 deletions(-) create mode 100644 core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java delete mode 100644 core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java delete mode 100644 core/src/main/java/com/microsoft/applicationinsights/internal/util/TemporaryExceptionWrapper.java create mode 100644 core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java delete mode 100644 core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java index dce4da3e819..674a0c46b17 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/ActiveTransmissionNetworkOutput.java @@ -21,9 +21,7 @@ package com.microsoft.applicationinsights.internal.channel.common; -import java.util.concurrent.Executors; import java.util.concurrent.RejectedExecutionException; -import java.util.concurrent.ScheduledExecutorService; import java.util.concurrent.ThreadPoolExecutor; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicInteger; @@ -31,8 +29,6 @@ import com.google.common.base.Preconditions; import com.microsoft.applicationinsights.internal.channel.TransmissionOutputAsync; import com.microsoft.applicationinsights.internal.channel.TransmissionOutputSync; -import com.microsoft.applicationinsights.internal.heartbeat.HeartBeatProvider; -import com.microsoft.applicationinsights.internal.util.NetworkExceptionsTracker; import com.microsoft.applicationinsights.internal.util.ThreadPoolUtils; /** @@ -50,8 +46,6 @@ public final class ActiveTransmissionNetworkOutput implements TransmissionOutput private final TransmissionOutputSync actualOutput; private final TransmissionPolicyStateFetcher transmissionPolicy; private final int instanceId = INTSTANCE_ID_POOL.getAndIncrement(); - private final ScheduledExecutorService networkIssueTracker = - Executors.newSingleThreadScheduledExecutor(ThreadPoolUtils.createDaemonThreadFactory(NetworkExceptionsTracker.class, "networkIssueTracker")); public ActiveTransmissionNetworkOutput(TransmissionOutputSync actualOutput, TransmissionPolicyStateFetcher transmissionPolicy) { this(actualOutput, transmissionPolicy, DEFAULT_MAX_MESSAGES_IN_BUFFER); @@ -62,8 +56,6 @@ public ActiveTransmissionNetworkOutput(TransmissionOutputSync actualOutput, Tran this.actualOutput = actualOutput; this.transmissionPolicy = transmissionPolicy; - // Schedule to run every 5 minutes - this.networkIssueTracker.scheduleAtFixedRate(new NetworkExceptionsTracker(), 300, 300, TimeUnit.SECONDS); maxThreads = DEFAULT_MAX_NUMBER_OF_THREADS; outputThreads = ThreadPoolUtils.newLimitedThreadPool( diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java index 2c9abfcb037..3962830907f 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java @@ -21,13 +21,20 @@ package com.microsoft.applicationinsights.internal.channel.common; +import java.io.IOException; +import java.net.SocketException; +import java.net.SocketTimeoutException; +import java.net.UnknownHostException; +import java.util.concurrent.atomic.AtomicBoolean; +import javax.annotation.Nullable; + import com.google.common.base.Preconditions; import com.microsoft.applicationinsights.TelemetryConfiguration; import com.microsoft.applicationinsights.customExceptions.FriendlyException; -import com.microsoft.applicationinsights.internal.util.TemporaryExceptionWrapper; import com.microsoft.applicationinsights.internal.channel.TransmissionDispatcher; import com.microsoft.applicationinsights.internal.channel.TransmissionHandlerArgs; import com.microsoft.applicationinsights.internal.channel.TransmissionOutputSync; +import com.microsoft.applicationinsights.internal.util.ExceptionStats; import org.apache.commons.lang3.StringUtils; import org.apache.http.Header; import org.apache.http.HttpEntity; @@ -40,14 +47,6 @@ import org.slf4j.Logger; import org.slf4j.LoggerFactory; -import javax.annotation.Nullable; -import java.io.IOException; -import java.net.SocketException; -import java.net.SocketTimeoutException; -import java.net.UnknownHostException; -import java.util.concurrent.atomic.AtomicBoolean; -import java.util.concurrent.atomic.AtomicReference; - /** * The class is responsible for the actual sending of * {@link com.microsoft.applicationinsights.internal.channel.common.Transmission} @@ -59,9 +58,8 @@ public final class TransmissionNetworkOutput implements TransmissionOutputSync { private static final Logger logger = LoggerFactory.getLogger(TransmissionNetworkOutput.class); - private static volatile AtomicBoolean friendlyExceptionThrown = new AtomicBoolean(); - public static final AtomicBoolean firstFailure = new AtomicBoolean(false); - public static volatile AtomicReference temporaryNetworkException = new AtomicReference<>(new TemporaryExceptionWrapper()); + private static final AtomicBoolean friendlyExceptionThrown = new AtomicBoolean(); + public static final ExceptionStats networkExceptionStats = new ExceptionStats(); private static final String CONTENT_TYPE_HEADER = "Content-Type"; private static final String CONTENT_ENCODING_HEADER = "Content-Encoding"; @@ -182,30 +180,32 @@ public boolean sendSync(Transmission transmission) { } // Increment Success Counter - temporaryNetworkException.set(new TemporaryExceptionWrapper(temporaryNetworkException.get().getSuccessCounter()+1, - temporaryNetworkException.get().getFailureCounter(), - temporaryNetworkException.get().getLastTemporaryException(), - temporaryNetworkException.get().getLastTemporaryExceptionLogger(), - temporaryNetworkException.get().getLastTemporaryExceptionMessage())); + networkExceptionStats.recordSuccess(); return true; } catch (ConnectionPoolTimeoutException e) { - handleTemporaryException("Failed to send, connection pool timeout exception. ", logger, e); + networkExceptionStats.recordException( + "Failed to send, connection pool timeout exception. " + TEMPORARY_EXCEPTION_MESSAGE, e, logger); } catch (SocketException e) { - handleTemporaryException("Failed to send, socket exception. ", logger, e); + networkExceptionStats.recordException( + "Failed to send, socket exception. " + TEMPORARY_EXCEPTION_MESSAGE, e, logger); } catch (SocketTimeoutException e) { - handleTemporaryException("Failed to send, socket timeout exception. ", logger, e); + networkExceptionStats.recordException( + "Failed to send, socket timeout exception. " + TEMPORARY_EXCEPTION_MESSAGE, e, logger); } catch (UnknownHostException e) { - handleTemporaryException("Failed to send, wrong host address or cannot reach address due to network issues. ", logger, e); + networkExceptionStats.recordException( + "Failed to send, wrong host address or cannot reach address due to network issues. " + TEMPORARY_EXCEPTION_MESSAGE, e, logger); } catch (IOException e) { - handleTemporaryException("Failed to send, IO exception. ", logger, e); + networkExceptionStats.recordException( + "Failed to send, IO exception. " + TEMPORARY_EXCEPTION_MESSAGE, e, logger); } catch (FriendlyException e) { ex = e; if(!friendlyExceptionThrown.getAndSet(true)) { logger.error(e.getMessage()); } } catch (Exception e) { - handleTemporaryException("Failed to send, unexpected exception. ", logger, e); + networkExceptionStats.recordException( + "Failed to send, unexpected exception. " + TEMPORARY_EXCEPTION_MESSAGE, e, logger); } catch (ThreadDeath td) { throw td; } catch (Throwable t) { @@ -247,28 +247,6 @@ public boolean sendSync(Transmission transmission) { return true; } - private static void handleTemporaryException(String message, Logger logger, Exception ex) { - // We log the first exception as soon as it is thrown - if(!firstFailure.getAndSet(true)) { - logger.error(message+"\n"+ - "Total number of successful telemetry requests so far:"+ temporaryNetworkException.get().getSuccessCounter()+"\n"+ - "Future failures will be aggregated and logged once every 5 minutes\n", ex); - } - - if(temporaryNetworkException.get().getFailureCounter() == 0) { - temporaryNetworkException.set(new TemporaryExceptionWrapper(temporaryNetworkException.get().getSuccessCounter(), - temporaryNetworkException.get().getFailureCounter()+1, ex, logger, - message+TEMPORARY_EXCEPTION_MESSAGE)); - } else { - temporaryNetworkException.set(new TemporaryExceptionWrapper(temporaryNetworkException.get().getSuccessCounter(), - temporaryNetworkException.get().getFailureCounter()+1, - temporaryNetworkException.get().getLastTemporaryException(), - temporaryNetworkException.get().getLastTemporaryExceptionLogger(), - temporaryNetworkException.get().getLastTemporaryExceptionMessage())); - } - - } - /** * Generates the HTTP POST to send to the endpoint. * diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java b/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java new file mode 100644 index 00000000000..d9c0f4e4c79 --- /dev/null +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java @@ -0,0 +1,81 @@ +package com.microsoft.applicationinsights.internal.util; + +import java.util.concurrent.Executors; +import java.util.concurrent.ScheduledExecutorService; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicBoolean; + +import org.slf4j.Logger; + +// exception stats for a given 5-min window +public class ExceptionStats { + + private static final ScheduledExecutorService scheduledExecutor = + Executors.newSingleThreadScheduledExecutor(ThreadPoolUtils.createDaemonThreadFactory(ExceptionStats.class, "exception stats logger")); + + private final AtomicBoolean firstFailure = new AtomicBoolean(false); + + // number of successes and failures in the 5-min window + private long numSuccesses; + private long numFailures; + + // these represent the first exception recorded in the 5-min window + private String warningMessage; + private Exception exception; + private Logger logger; + + private final Object lock = new Object(); + + public void recordSuccess() { + numSuccesses++; + } + + public void recordException(String warningMessage, Exception exception, Logger logger) { + // log the first exception as soon as it occurs, then log only every 5 min after that + if (!firstFailure.getAndSet(true)) { + logger.warn(warningMessage + " (future failures will be aggregated and logged once every 5 minutes)", exception); + scheduledExecutor.scheduleAtFixedRate(new ExceptionStatsLogger(), 5, 5, TimeUnit.MINUTES); + return; + } + + synchronized (lock) { + if (numFailures == 0) { + this.warningMessage = warningMessage; + this.exception = exception; + this.logger = logger; + } + numFailures++; + } + } + + public class ExceptionStatsLogger implements Runnable { + + @Override + public void run() { + long numSuccesses; + long numFailures; + String warningMessage; + Exception exception; + Logger logger; + // grab quickly and reset under lock (do not perform logging under lock) + synchronized (lock) { + numSuccesses = ExceptionStats.this.numSuccesses; + numFailures = ExceptionStats.this.numFailures; + warningMessage = ExceptionStats.this.warningMessage; + exception = ExceptionStats.this.exception; + logger = ExceptionStats.this.logger; + + ExceptionStats.this.numSuccesses = 0; + ExceptionStats.this.numFailures = 0; + ExceptionStats.this.warningMessage = null; + ExceptionStats.this.exception = null; + ExceptionStats.this.logger = null; + } + if (numFailures > 0) { + logger.error(warningMessage + "\n" + + "Total number of failed telemetry requests in the last 5 minutes: " + numFailures + "\n" + + "Total number of successful telemetry requests in the last 5 minutes: " + numSuccesses + "\n", exception); + } + } + } +} diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java b/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java deleted file mode 100644 index b85cd23536d..00000000000 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTracker.java +++ /dev/null @@ -1,17 +0,0 @@ -package com.microsoft.applicationinsights.internal.util; - -import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.temporaryNetworkException; - -public class NetworkExceptionsTracker implements Runnable{ - @Override public void run() { - TemporaryExceptionWrapper temporaryExceptionWrapper = temporaryNetworkException.get(); - if(temporaryExceptionWrapper.getFailureCounter() > 0 && temporaryExceptionWrapper.getLastTemporaryExceptionLogger()!=null) { - temporaryExceptionWrapper.getLastTemporaryExceptionLogger().error(temporaryExceptionWrapper.getLastTemporaryExceptionMessage()+"\n"+ - "Total number of failed telemetry requests in the last 5 minutes:"+ temporaryExceptionWrapper.getFailureCounter()+"\n"+ - "Total number of successful telemetry requests in the last 5 minutes:"+ temporaryExceptionWrapper.getSuccessCounter()+"\n", - temporaryExceptionWrapper.getLastTemporaryException() - ); - } - temporaryNetworkException.set(new TemporaryExceptionWrapper()); - } -} diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/util/TemporaryExceptionWrapper.java b/core/src/main/java/com/microsoft/applicationinsights/internal/util/TemporaryExceptionWrapper.java deleted file mode 100644 index 34588fd5429..00000000000 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/util/TemporaryExceptionWrapper.java +++ /dev/null @@ -1,53 +0,0 @@ -package com.microsoft.applicationinsights.internal.util; -import org.slf4j.Logger; - -public class TemporaryExceptionWrapper { - private long successCounter; - private long failureCounter; - private Exception lastTemporaryException; - private Logger lastTemporaryExceptionLogger; - private String lastTemporaryExceptionMessage; - - public TemporaryExceptionWrapper() { - this.successCounter = 0L; - this.failureCounter = 0L; - } - - public TemporaryExceptionWrapper(long successCounter, long failureCounter, Exception lastTemporaryException, Logger lastTemporaryExceptionLogger, String lastTemporaryExceptionMessage) { - this.successCounter = successCounter; - this.failureCounter = failureCounter; - this.lastTemporaryException = lastTemporaryException; - this.lastTemporaryExceptionLogger = lastTemporaryExceptionLogger; - this.lastTemporaryExceptionMessage = lastTemporaryExceptionMessage; - } - - public long getSuccessCounter() { - return successCounter; - } - - public long getFailureCounter() { - return failureCounter; - } - - public Exception getLastTemporaryException() { - return lastTemporaryException; - } - - public Logger getLastTemporaryExceptionLogger() { - return lastTemporaryExceptionLogger; - } - - public String getLastTemporaryExceptionMessage() { - return lastTemporaryExceptionMessage; - } - - // only used in tests - public void incrementSuccessCounter() { - ++this.successCounter; - } - - //only used in tests - public void incrementFailureCounter() { - ++this.failureCounter; - } -} diff --git a/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java b/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java new file mode 100644 index 00000000000..be138e7d1c6 --- /dev/null +++ b/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java @@ -0,0 +1,81 @@ +package com.microsoft.applicationinsights.internal.util; + +import java.util.concurrent.Executors; +import java.util.concurrent.ScheduledExecutorService; +import java.util.concurrent.TimeUnit; + +import nl.altindag.log.LogCaptor; +import org.junit.*; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.networkExceptionStats; +import static org.junit.Assert.*; + +public class ExceptionStatsLoggerTest { + private static final ScheduledExecutorService networkIssueTrackerTest = + Executors.newSingleThreadScheduledExecutor( + ThreadPoolUtils.createDaemonThreadFactory( + NetworkExceptionsTracker.class, + "networkIssueTrackerTest")); + + @BeforeClass + public static void setUp() { + // one-time initialization code + networkIssueTrackerTest.scheduleAtFixedRate(new NetworkExceptionsTracker(), 0, 1, TimeUnit.MILLISECONDS); + } + + @After + public void tearDown() throws InterruptedException { + // cleanup code + networkExceptionStats.set(new ExceptionStats()); + } + + @AfterClass + public static void cleanup() throws InterruptedException { + if (!networkIssueTrackerTest.isShutdown()) { + networkIssueTrackerTest.shutdown(); + } + networkIssueTrackerTest.awaitTermination(2, TimeUnit.SECONDS); + } + + + @Test + public void testSuccessAndFailureCounters() throws InterruptedException { + ExceptionStats exceptionStats = networkExceptionStats.get(); + assertEquals(0L, exceptionStats.getNumFailures()); + assertEquals(0L, exceptionStats.getNumSuccesses()); + exceptionStats.incrementSuccessCounter(); + assertEquals(1L, exceptionStats.getNumSuccesses()); + Logger logger = LoggerFactory.getLogger(ExceptionStatsLoggerTest.class); + Exception ex=new IllegalArgumentException(); + networkExceptionStats.set(new ExceptionStats(networkExceptionStats.get().getSuccessCounter(), + networkExceptionStats.get().getFailureCounter()+1, ex, logger, "Test Message")); + assertEquals(1L, networkExceptionStats.get().getFailureCounter()); + assertEquals(ex, networkExceptionStats.get().getException()); + assertEquals("Test Message", networkExceptionStats.get().getWarningMessage()); + assertEquals(logger, networkExceptionStats.get().getLogger()); + } + + @Test + public void testExceptionLogged() throws InterruptedException { + LogCaptor logCaptor = LogCaptor.forClass(ExceptionStatsLoggerTest.class); + ExceptionStats exceptionStats = networkExceptionStats.get(); + assertEquals(0L, exceptionStats.getNumFailures()); + assertEquals(0L, exceptionStats.getNumSuccesses()); + exceptionStats.incrementSuccessCounter(); + assertEquals(1L, exceptionStats.getNumSuccesses()); + Logger logger = LoggerFactory.getLogger(ExceptionStatsLoggerTest.class); + Exception ex=new IllegalArgumentException(); + networkExceptionStats.set(new ExceptionStats(networkExceptionStats.get().getSuccessCounter(), + networkExceptionStats.get().getFailureCounter()+1, ex, logger, "Test Message")); + assertEquals(1L, networkExceptionStats.get().getFailureCounter()); + assertEquals(ex, networkExceptionStats.get().getException()); + assertEquals("Test Message", networkExceptionStats.get().getWarningMessage()); + assertEquals(logger, networkExceptionStats.get().getLogger()); + //wait for 3 secs + Thread.sleep(3000); + assertEquals(1,logCaptor.getErrorLogs().size()); + } + +} diff --git a/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java b/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java deleted file mode 100644 index e805ecc8640..00000000000 --- a/core/src/test/java/com/microsoft/applicationinsights/internal/util/NetworkExceptionsTrackerTest.java +++ /dev/null @@ -1,81 +0,0 @@ -package com.microsoft.applicationinsights.internal.util; - -import java.util.concurrent.Executors; -import java.util.concurrent.ScheduledExecutorService; -import java.util.concurrent.TimeUnit; - -import nl.altindag.log.LogCaptor; -import org.junit.*; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - -import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.temporaryNetworkException; -import static org.junit.Assert.*; - -public class NetworkExceptionsTrackerTest { - private static final ScheduledExecutorService networkIssueTrackerTest = - Executors.newSingleThreadScheduledExecutor( - ThreadPoolUtils.createDaemonThreadFactory( - NetworkExceptionsTracker.class, - "networkIssueTrackerTest")); - - @BeforeClass - public static void setUp() { - // one-time initialization code - networkIssueTrackerTest.scheduleAtFixedRate(new NetworkExceptionsTracker(), 0, 1, TimeUnit.MILLISECONDS); - } - - @After - public void tearDown() throws InterruptedException { - // cleanup code - temporaryNetworkException.set(new TemporaryExceptionWrapper()); - } - - @AfterClass - public static void cleanup() throws InterruptedException { - if (!networkIssueTrackerTest.isShutdown()) { - networkIssueTrackerTest.shutdown(); - } - networkIssueTrackerTest.awaitTermination(2, TimeUnit.SECONDS); - } - - - @Test - public void testSuccessAndFailureCounters() throws InterruptedException { - TemporaryExceptionWrapper temporaryExceptionWrapper = temporaryNetworkException.get(); - assertEquals(0L, temporaryExceptionWrapper.getFailureCounter()); - assertEquals(0L, temporaryExceptionWrapper.getSuccessCounter()); - temporaryExceptionWrapper.incrementSuccessCounter(); - assertEquals(1L, temporaryExceptionWrapper.getSuccessCounter()); - Logger logger = LoggerFactory.getLogger(NetworkExceptionsTrackerTest.class); - Exception ex=new IllegalArgumentException(); - temporaryNetworkException.set(new TemporaryExceptionWrapper(temporaryNetworkException.get().getSuccessCounter(), - temporaryNetworkException.get().getFailureCounter()+1, ex, logger, "Test Message")); - assertEquals(1L, temporaryNetworkException.get().getFailureCounter()); - assertEquals(ex,temporaryNetworkException.get().getLastTemporaryException()); - assertEquals("Test Message",temporaryNetworkException.get().getLastTemporaryExceptionMessage()); - assertEquals(logger,temporaryNetworkException.get().getLastTemporaryExceptionLogger()); - } - - @Test - public void testExceptionLogged() throws InterruptedException { - LogCaptor logCaptor = LogCaptor.forClass(NetworkExceptionsTrackerTest.class); - TemporaryExceptionWrapper temporaryExceptionWrapper = temporaryNetworkException.get(); - assertEquals(0L, temporaryExceptionWrapper.getFailureCounter()); - assertEquals(0L, temporaryExceptionWrapper.getSuccessCounter()); - temporaryExceptionWrapper.incrementSuccessCounter(); - assertEquals(1L, temporaryExceptionWrapper.getSuccessCounter()); - Logger logger = LoggerFactory.getLogger(NetworkExceptionsTrackerTest.class); - Exception ex=new IllegalArgumentException(); - temporaryNetworkException.set(new TemporaryExceptionWrapper(temporaryNetworkException.get().getSuccessCounter(), - temporaryNetworkException.get().getFailureCounter()+1, ex, logger, "Test Message")); - assertEquals(1L, temporaryNetworkException.get().getFailureCounter()); - assertEquals(ex,temporaryNetworkException.get().getLastTemporaryException()); - assertEquals("Test Message",temporaryNetworkException.get().getLastTemporaryExceptionMessage()); - assertEquals(logger,temporaryNetworkException.get().getLastTemporaryExceptionLogger()); - //wait for 3 secs - Thread.sleep(3000); - assertEquals(1,logCaptor.getErrorLogs().size()); - } - -} From c4018cef446cb7b49a81f2f1d42a004d2b86103a Mon Sep 17 00:00:00 2001 From: kryalama <66494519+kryalama@users.noreply.github.com> Date: Tue, 23 Feb 2021 15:25:58 -0800 Subject: [PATCH 10/18] better encapsulation in ExceptionStats --- .../common/TransmissionNetworkOutput.java | 6 +- .../internal/util/ExceptionStats.java | 16 ++++- .../util/ExceptionStatsLoggerTest.java | 67 +++---------------- 3 files changed, 28 insertions(+), 61 deletions(-) diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java index 3962830907f..cd309cd25dd 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java @@ -177,12 +177,10 @@ public boolean sendSync(Transmission transmission) { // If we've completed then clear the back off flags as the channel does not need // to be throttled transmissionPolicyManager.clearBackoff(); + // Increment Success Counter + networkExceptionStats.recordSuccess(); } - - // Increment Success Counter - networkExceptionStats.recordSuccess(); return true; - } catch (ConnectionPoolTimeoutException e) { networkExceptionStats.recordException( "Failed to send, connection pool timeout exception. " + TEMPORARY_EXCEPTION_MESSAGE, e, logger); diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java b/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java index d9c0f4e4c79..3ca5ba6c422 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java @@ -23,8 +23,22 @@ public class ExceptionStats { private String warningMessage; private Exception exception; private Logger logger; + // Initial Delay for scheduled executor in milliseconds + private int executorInitialDelay; + // Period for scheduled executor in milliseconds + private int executorPeriod; private final Object lock = new Object(); + // Primarily used by test + public ExceptionStats(int executorInitialDelay, int executorPeriod) { + this.executorInitialDelay = executorInitialDelay; + this.executorPeriod = executorPeriod; + } + + public ExceptionStats() { + this.executorInitialDelay = 300; + this.executorPeriod = 300; + } public void recordSuccess() { numSuccesses++; @@ -34,7 +48,7 @@ public void recordException(String warningMessage, Exception exception, Logger l // log the first exception as soon as it occurs, then log only every 5 min after that if (!firstFailure.getAndSet(true)) { logger.warn(warningMessage + " (future failures will be aggregated and logged once every 5 minutes)", exception); - scheduledExecutor.scheduleAtFixedRate(new ExceptionStatsLogger(), 5, 5, TimeUnit.MINUTES); + scheduledExecutor.scheduleAtFixedRate(new ExceptionStatsLogger(), executorInitialDelay, executorPeriod, TimeUnit.SECONDS); return; } diff --git a/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java b/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java index be138e7d1c6..6cba4627478 100644 --- a/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java +++ b/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java @@ -1,81 +1,36 @@ package com.microsoft.applicationinsights.internal.util; -import java.util.concurrent.Executors; -import java.util.concurrent.ScheduledExecutorService; -import java.util.concurrent.TimeUnit; - import nl.altindag.log.LogCaptor; import org.junit.*; import org.slf4j.Logger; import org.slf4j.LoggerFactory; -import static com.microsoft.applicationinsights.internal.channel.common.TransmissionNetworkOutput.networkExceptionStats; import static org.junit.Assert.*; public class ExceptionStatsLoggerTest { - private static final ScheduledExecutorService networkIssueTrackerTest = - Executors.newSingleThreadScheduledExecutor( - ThreadPoolUtils.createDaemonThreadFactory( - NetworkExceptionsTracker.class, - "networkIssueTrackerTest")); + private static ExceptionStats networkExceptionStats; + private static Logger logger; @BeforeClass public static void setUp() { // one-time initialization code - networkIssueTrackerTest.scheduleAtFixedRate(new NetworkExceptionsTracker(), 0, 1, TimeUnit.MILLISECONDS); - } - - @After - public void tearDown() throws InterruptedException { - // cleanup code - networkExceptionStats.set(new ExceptionStats()); - } - - @AfterClass - public static void cleanup() throws InterruptedException { - if (!networkIssueTrackerTest.isShutdown()) { - networkIssueTrackerTest.shutdown(); - } - networkIssueTrackerTest.awaitTermination(2, TimeUnit.SECONDS); - } - - - @Test - public void testSuccessAndFailureCounters() throws InterruptedException { - ExceptionStats exceptionStats = networkExceptionStats.get(); - assertEquals(0L, exceptionStats.getNumFailures()); - assertEquals(0L, exceptionStats.getNumSuccesses()); - exceptionStats.incrementSuccessCounter(); - assertEquals(1L, exceptionStats.getNumSuccesses()); - Logger logger = LoggerFactory.getLogger(ExceptionStatsLoggerTest.class); - Exception ex=new IllegalArgumentException(); - networkExceptionStats.set(new ExceptionStats(networkExceptionStats.get().getSuccessCounter(), - networkExceptionStats.get().getFailureCounter()+1, ex, logger, "Test Message")); - assertEquals(1L, networkExceptionStats.get().getFailureCounter()); - assertEquals(ex, networkExceptionStats.get().getException()); - assertEquals("Test Message", networkExceptionStats.get().getWarningMessage()); - assertEquals(logger, networkExceptionStats.get().getLogger()); + networkExceptionStats = new ExceptionStats(0,1); + logger = LoggerFactory.getLogger(ExceptionStatsLoggerTest.class); } @Test - public void testExceptionLogged() throws InterruptedException { + public void testWarnAndExceptionLogged() throws InterruptedException { LogCaptor logCaptor = LogCaptor.forClass(ExceptionStatsLoggerTest.class); - ExceptionStats exceptionStats = networkExceptionStats.get(); - assertEquals(0L, exceptionStats.getNumFailures()); - assertEquals(0L, exceptionStats.getNumSuccesses()); - exceptionStats.incrementSuccessCounter(); - assertEquals(1L, exceptionStats.getNumSuccesses()); - Logger logger = LoggerFactory.getLogger(ExceptionStatsLoggerTest.class); + networkExceptionStats.recordSuccess(); Exception ex=new IllegalArgumentException(); - networkExceptionStats.set(new ExceptionStats(networkExceptionStats.get().getSuccessCounter(), - networkExceptionStats.get().getFailureCounter()+1, ex, logger, "Test Message")); - assertEquals(1L, networkExceptionStats.get().getFailureCounter()); - assertEquals(ex, networkExceptionStats.get().getException()); - assertEquals("Test Message", networkExceptionStats.get().getWarningMessage()); - assertEquals(logger, networkExceptionStats.get().getLogger()); + networkExceptionStats.recordException("Test Message",ex,logger); + networkExceptionStats.recordException("Test Message2",ex,logger); //wait for 3 secs Thread.sleep(3000); assertEquals(1,logCaptor.getErrorLogs().size()); + assertEquals(1,logCaptor.getWarnLogs().size()); + assertTrue(logCaptor.getErrorLogs().get(0).contains("Total number of failed telemetry requests in the last 5 minutes: 1")); + assertTrue(logCaptor.getErrorLogs().get(0).contains("Total number of successful telemetry requests in the last 5 minutes: 1")); } } From 55a96272affad4de5b81ecfc55b46f279c77a5c3 Mon Sep 17 00:00:00 2001 From: kryalama <66494519+kryalama@users.noreply.github.com> Date: Tue, 23 Feb 2021 16:48:26 -0800 Subject: [PATCH 11/18] added code to handle memory exceptions --- .../common/TransmissionFileSystemOutput.java | 26 +++++++------- .../common/TransmissionNetworkOutput.java | 2 +- .../internal/util/ExceptionStats.java | 35 +++++++++++++++---- .../util/ExceptionStatsLoggerTest.java | 6 ++-- 4 files changed, 47 insertions(+), 22 deletions(-) diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java index 98def3c36aa..5e20f28bc8b 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java @@ -45,6 +45,7 @@ import java.util.concurrent.atomic.AtomicLong; import com.microsoft.applicationinsights.internal.channel.TransmissionOutputSync; +import com.microsoft.applicationinsights.internal.util.ExceptionStats; import com.microsoft.applicationinsights.internal.util.LimitsEnforcer; import com.microsoft.applicationinsights.internal.util.LocalFileSystemUtils; import org.apache.commons.io.FileUtils; @@ -84,6 +85,7 @@ public final class TransmissionFileSystemOutput implements TransmissionOutputSyn private final static int MAX_CAPACITY_MEGABYTES = 1000; private final static int MIN_CAPACITY_MEGABYTES = 1; private static final String MAX_TRANSMISSION_STORAGE_CAPACITY_NAME = "Channel.MaxTransmissionStorageCapacityInMB"; + public static final ExceptionStats memoryExceptionStats = new ExceptionStats(); /// The folder in which we save transmission files @@ -140,10 +142,9 @@ public boolean sendSync(Transmission transmission) { long currentSizeInBytes = size.get(); if (currentSizeInBytes >= capacityInBytes) { - logger.error("Persistent storage max capacity has been reached; " - + "currently at {} bytes. Telemetry will be lost, " - + "please consider increasing the value of MaxTransmissionStorageFilesCapacityInMB property in the configuration file.", - currentSizeInBytes); + memoryExceptionStats.recordError("Persistent storage max capacity has been reached; " + + "currently at "+ currentSizeInBytes +" bytes. Telemetry will be lost, " + + "please consider increasing the value of MaxTransmissionStorageFilesCapacityInMB property in the configuration file.",logger); return false; } @@ -161,6 +162,7 @@ public boolean sendSync(Transmission transmission) { } logger.debug("Data persisted to file. To be sent when the network is available."); + memoryExceptionStats.recordSuccess(); return true; } @@ -203,7 +205,7 @@ public Transmission fetchOldestFile() { } } } catch (Exception e) { - logger.error("Error fetching oldest file", e); + memoryExceptionStats.recordException("Error fetching oldest file", e, logger); } return null; @@ -245,11 +247,11 @@ private Optional loadTransmission(File file) { try (ObjectInput input = new SafeObjectInputStream(new BufferedInputStream(new FileInputStream(file)))) { transmission = (Transmission)input.readObject(); } catch (FileNotFoundException e) { - logger.error("Failed to load transmission, file not found, exception: {}", e.toString()); + memoryExceptionStats.recordException("Failed to load transmission, file not found", e, logger); } catch (ClassNotFoundException e) { - logger.error("Failed to load transmission, non transmission, exception: {}", e.toString()); + memoryExceptionStats.recordException("Failed to load transmission, non transmission", e, logger); } catch (IOException e) { - logger.error("Failed to load transmission, io exception: {}", e.toString()); + memoryExceptionStats.recordException("Failed to load transmission, io exception", e, logger); } return Optional.fromNullable(transmission); @@ -278,7 +280,7 @@ private boolean renameToPermanentName(File tempTransmissionFile) { size.addAndGet(fileLength); return true; } catch (Exception e) { - logger.error("Rename To Permanent Name failed, exception: {}", e.toString()); + memoryExceptionStats.recordException("Rename To Permanent Name failed", e, logger); } return false; @@ -292,7 +294,7 @@ private Optional renameToTemporaryName(File tempTransmissionFile) { size.addAndGet(-renamedFile.length()); transmissionFile = renamedFile; } catch (Exception ignore) { - logger.error("Rename To Temporary Name failed, exception: {}", ignore.toString()); + memoryExceptionStats.recordException("Rename To Temporary Name failed", ignore, logger); // Consume the exception, since there isn't anything 'smart' to do now } @@ -305,7 +307,7 @@ private boolean saveTransmission(File transmissionFile, Transmission transmissio output.writeObject(transmission); return true; } catch (IOException e) { - logger.error("Failed to save transmission, exception: {}", e.toString()); + memoryExceptionStats.recordException("Failed to save transmission", e, logger); } return false; @@ -317,7 +319,7 @@ private Optional createTemporaryFile() { String prefix = TRANSMISSION_FILE_PREFIX + "-" + System.currentTimeMillis() + "-"; file = File.createTempFile(prefix, null, folder); } catch (IOException e) { - logger.error("Failed to create temporary file, exception: {}", e.toString()); + memoryExceptionStats.recordException("Failed to create temporary file", e, logger); } return Optional.fromNullable(file); diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java index cd309cd25dd..f3c3943de82 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java @@ -222,7 +222,7 @@ public boolean sendSync(Transmission transmission) { httpClient.dispose(response); if (code == HttpStatus.SC_BAD_REQUEST) { - logger.error("Error sending data: {}", reason); + networkExceptionStats.recordError("Error sending data: "+reason, logger); } else if (code != HttpStatus.SC_OK) { // Invoke the listeners for handling things like errors // The listeners will handle the back off logic as well as the dispatch diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java b/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java index 3ca5ba6c422..4ed004d1232 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java @@ -23,9 +23,9 @@ public class ExceptionStats { private String warningMessage; private Exception exception; private Logger logger; - // Initial Delay for scheduled executor in milliseconds + // Initial Delay for scheduled executor in secs private int executorInitialDelay; - // Period for scheduled executor in milliseconds + // Period for scheduled executor in secs private int executorPeriod; private final Object lock = new Object(); @@ -47,7 +47,7 @@ public void recordSuccess() { public void recordException(String warningMessage, Exception exception, Logger logger) { // log the first exception as soon as it occurs, then log only every 5 min after that if (!firstFailure.getAndSet(true)) { - logger.warn(warningMessage + " (future failures will be aggregated and logged once every 5 minutes)", exception); + logger.warn(warningMessage + " (future failures will be aggregated and logged once every "+ this.executorPeriod/60 +" minutes)", exception); scheduledExecutor.scheduleAtFixedRate(new ExceptionStatsLogger(), executorInitialDelay, executorPeriod, TimeUnit.SECONDS); return; } @@ -62,6 +62,23 @@ public void recordException(String warningMessage, Exception exception, Logger l } } + public void recordError(String warningMessage, Logger logger) { + // log the first exception as soon as it occurs, then log only every 5 min after that + if (!firstFailure.getAndSet(true)) { + logger.warn(warningMessage + " (future failures will be aggregated and logged once every "+ this.executorPeriod/60 +" minutes)"); + scheduledExecutor.scheduleAtFixedRate(new ExceptionStatsLogger(), executorInitialDelay, executorPeriod, TimeUnit.SECONDS); + return; + } + + synchronized (lock) { + if (numFailures == 0) { + this.warningMessage = warningMessage; + this.logger = logger; + } + numFailures++; + } + } + public class ExceptionStatsLogger implements Runnable { @Override @@ -86,9 +103,15 @@ public void run() { ExceptionStats.this.logger = null; } if (numFailures > 0) { - logger.error(warningMessage + "\n" + - "Total number of failed telemetry requests in the last 5 minutes: " + numFailures + "\n" + - "Total number of successful telemetry requests in the last 5 minutes: " + numSuccesses + "\n", exception); + if(exception == null) { + logger.error(warningMessage + "\n" + + "Total number of failed telemetry requests in the last "+ ExceptionStats.this.executorPeriod/60 + "minutes: " + numFailures + "\n" + + "Total number of successful telemetry requests in the last "+ ExceptionStats.this.executorPeriod/60 + " minutes: " + numSuccesses + "\n"); + } else { + logger.error(warningMessage + "\n" + + "Total number of failed telemetry requests in the last "+ ExceptionStats.this.executorPeriod/60 + " minutes: " + numFailures + "\n" + + "Total number of successful telemetry requests in the last "+ ExceptionStats.this.executorPeriod/60 + " minutes: " + numSuccesses + "\n", exception); + } } } } diff --git a/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java b/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java index 6cba4627478..666f162a31b 100644 --- a/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java +++ b/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java @@ -14,7 +14,7 @@ public class ExceptionStatsLoggerTest { @BeforeClass public static void setUp() { // one-time initialization code - networkExceptionStats = new ExceptionStats(0,1); + networkExceptionStats = new ExceptionStats(3,3); logger = LoggerFactory.getLogger(ExceptionStatsLoggerTest.class); } @@ -29,8 +29,8 @@ public void testWarnAndExceptionLogged() throws InterruptedException { Thread.sleep(3000); assertEquals(1,logCaptor.getErrorLogs().size()); assertEquals(1,logCaptor.getWarnLogs().size()); - assertTrue(logCaptor.getErrorLogs().get(0).contains("Total number of failed telemetry requests in the last 5 minutes: 1")); - assertTrue(logCaptor.getErrorLogs().get(0).contains("Total number of successful telemetry requests in the last 5 minutes: 1")); + assertTrue(logCaptor.getErrorLogs().get(0).contains("Total number of failed telemetry requests in the last 0 minutes: 1")); + assertTrue(logCaptor.getErrorLogs().get(0).contains("Total number of successful telemetry requests in the last 0 minutes: 1")); } } From ebad706911bd6fef30298f846502540cabd98092 Mon Sep 17 00:00:00 2001 From: kryalama <66494519+kryalama@users.noreply.github.com> Date: Wed, 24 Feb 2021 07:55:20 -0800 Subject: [PATCH 12/18] improved warning/error messages that capture failure counts --- .../internal/util/ExceptionStats.java | 106 +++++++++--------- .../util/ExceptionStatsLoggerTest.java | 18 ++- .../smoketest/SpringCloudStreamTest.java | 5 +- 3 files changed, 70 insertions(+), 59 deletions(-) diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java b/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java index 4ed004d1232..97e5174a171 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java @@ -1,117 +1,123 @@ package com.microsoft.applicationinsights.internal.util; +import java.util.HashMap; +import java.util.Map; import java.util.concurrent.Executors; import java.util.concurrent.ScheduledExecutorService; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicLong; +import com.microsoft.applicationinsights.internal.channel.common.TransmissionFileSystemOutput; import org.slf4j.Logger; +import org.slf4j.LoggerFactory; // exception stats for a given 5-min window +// each instance represents a logical grouping of errors that a user cares about and can understand, +// e.g. sending telemetry to the portal, storing telemetry to disk, ... public class ExceptionStats { private static final ScheduledExecutorService scheduledExecutor = Executors.newSingleThreadScheduledExecutor(ThreadPoolUtils.createDaemonThreadFactory(ExceptionStats.class, "exception stats logger")); - private final AtomicBoolean firstFailure = new AtomicBoolean(false); + private static final Logger logger = LoggerFactory.getLogger(ExceptionStats.class); + + // Period for scheduled executor in secs + private final int intervalSeconds; + + private final AtomicBoolean firstFailure = new AtomicBoolean(); + + // private final String groupingMessage; // number of successes and failures in the 5-min window private long numSuccesses; private long numFailures; - // these represent the first exception recorded in the 5-min window - private String warningMessage; - private Exception exception; - private Logger logger; - // Initial Delay for scheduled executor in secs - private int executorInitialDelay; - // Period for scheduled executor in secs - private int executorPeriod; + // using MutableLong for two purposes + // * so we don't need to get and set into map each time we want to increment + // * avoid autoboxing for values above 128 + private Map warningMessages = new HashMap<>(); private final Object lock = new Object(); - // Primarily used by test - public ExceptionStats(int executorInitialDelay, int executorPeriod) { - this.executorInitialDelay = executorInitialDelay; - this.executorPeriod = executorPeriod; - } public ExceptionStats() { - this.executorInitialDelay = 300; - this.executorPeriod = 300; + this(300); + } + + // Primarily used by test + public ExceptionStats(int intervalSeconds) { + this.intervalSeconds = intervalSeconds; } public void recordSuccess() { - numSuccesses++; + synchronized (lock) { + numSuccesses++; + } } + // warningMessage should have low cardinality public void recordException(String warningMessage, Exception exception, Logger logger) { - // log the first exception as soon as it occurs, then log only every 5 min after that if (!firstFailure.getAndSet(true)) { - logger.warn(warningMessage + " (future failures will be aggregated and logged once every "+ this.executorPeriod/60 +" minutes)", exception); - scheduledExecutor.scheduleAtFixedRate(new ExceptionStatsLogger(), executorInitialDelay, executorPeriod, TimeUnit.SECONDS); + // log the first time we see an exception as soon as it occurs + logger.warn(warningMessage + " (future failures will be aggregated and logged once every "+ this.intervalSeconds /60 +" minutes)", exception); + scheduledExecutor.scheduleAtFixedRate(new ExceptionStatsLogger(), intervalSeconds, intervalSeconds, TimeUnit.SECONDS); return; } + logger.debug(warningMessage, exception); + synchronized (lock) { - if (numFailures == 0) { - this.warningMessage = warningMessage; - this.exception = exception; - this.logger = logger; - } + warningMessages.computeIfAbsent(warningMessage, key -> new MutableLong()).increment(); numFailures++; } } public void recordError(String warningMessage, Logger logger) { - // log the first exception as soon as it occurs, then log only every 5 min after that if (!firstFailure.getAndSet(true)) { - logger.warn(warningMessage + " (future failures will be aggregated and logged once every "+ this.executorPeriod/60 +" minutes)"); - scheduledExecutor.scheduleAtFixedRate(new ExceptionStatsLogger(), executorInitialDelay, executorPeriod, TimeUnit.SECONDS); + // log the first time we see an exception as soon as it occurs + logger.warn(warningMessage + " (future failures will be aggregated and logged once every "+ this.intervalSeconds /60 +" minutes)"); + scheduledExecutor.scheduleAtFixedRate(new ExceptionStatsLogger(), intervalSeconds, intervalSeconds, TimeUnit.SECONDS); return; } + logger.debug(warningMessage); + synchronized (lock) { - if (numFailures == 0) { - this.warningMessage = warningMessage; - this.logger = logger; - } + warningMessages.computeIfAbsent(warningMessage, key -> new MutableLong()).increment(); numFailures++; } } + private static class MutableLong { + private long value; + private void increment() { + value++; + } + } + public class ExceptionStatsLogger implements Runnable { @Override public void run() { long numSuccesses; long numFailures; - String warningMessage; - Exception exception; - Logger logger; + Map warningMessages; // grab quickly and reset under lock (do not perform logging under lock) synchronized (lock) { numSuccesses = ExceptionStats.this.numSuccesses; numFailures = ExceptionStats.this.numFailures; - warningMessage = ExceptionStats.this.warningMessage; - exception = ExceptionStats.this.exception; - logger = ExceptionStats.this.logger; + warningMessages = ExceptionStats.this.warningMessages; ExceptionStats.this.numSuccesses = 0; ExceptionStats.this.numFailures = 0; - ExceptionStats.this.warningMessage = null; - ExceptionStats.this.exception = null; - ExceptionStats.this.logger = null; + ExceptionStats.this.warningMessages = new HashMap<>(); } if (numFailures > 0) { - if(exception == null) { - logger.error(warningMessage + "\n" + - "Total number of failed telemetry requests in the last "+ ExceptionStats.this.executorPeriod/60 + "minutes: " + numFailures + "\n" + - "Total number of successful telemetry requests in the last "+ ExceptionStats.this.executorPeriod/60 + " minutes: " + numSuccesses + "\n"); - } else { - logger.error(warningMessage + "\n" + - "Total number of failed telemetry requests in the last "+ ExceptionStats.this.executorPeriod/60 + " minutes: " + numFailures + "\n" + - "Total number of successful telemetry requests in the last "+ ExceptionStats.this.executorPeriod/60 + " minutes: " + numSuccesses + "\n", exception); - } + warningMessages.forEach( + (message,failureCount) -> logger.error(message+" (failed "+ failureCount.value + " times in the last "+ ExceptionStats.this.intervalSeconds/60 +" minutes)") + ); + logger.warn(numFailures+"/"+(numFailures+numSuccesses) + "(Total Failures/Total Requests) reported in the last "+ ExceptionStats.this.intervalSeconds/60 +" minutes"); + } } } diff --git a/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java b/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java index 666f162a31b..8cd5f37b36c 100644 --- a/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java +++ b/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java @@ -14,23 +14,29 @@ public class ExceptionStatsLoggerTest { @BeforeClass public static void setUp() { // one-time initialization code - networkExceptionStats = new ExceptionStats(3,3); + networkExceptionStats = new ExceptionStats(3); logger = LoggerFactory.getLogger(ExceptionStatsLoggerTest.class); } @Test - public void testWarnAndExceptionLogged() throws InterruptedException { - LogCaptor logCaptor = LogCaptor.forClass(ExceptionStatsLoggerTest.class); + public void testWarnAndExceptionsAreLogged() throws InterruptedException { + LogCaptor logCaptorLocal = LogCaptor.forClass(ExceptionStatsLoggerTest.class); + LogCaptor logCaptor = LogCaptor.forClass(ExceptionStats.class); networkExceptionStats.recordSuccess(); Exception ex=new IllegalArgumentException(); networkExceptionStats.recordException("Test Message",ex,logger); networkExceptionStats.recordException("Test Message2",ex,logger); + networkExceptionStats.recordException("Test Message2",ex,logger); + networkExceptionStats.recordException("Test Message3",ex,logger); //wait for 3 secs Thread.sleep(3000); - assertEquals(1,logCaptor.getErrorLogs().size()); + assertEquals(2,logCaptor.getErrorLogs().size()); assertEquals(1,logCaptor.getWarnLogs().size()); - assertTrue(logCaptor.getErrorLogs().get(0).contains("Total number of failed telemetry requests in the last 0 minutes: 1")); - assertTrue(logCaptor.getErrorLogs().get(0).contains("Total number of successful telemetry requests in the last 0 minutes: 1")); + System.out.println(logCaptor.getWarnLogs()); + assertTrue(logCaptor.getErrorLogs().get(0).contains("Test Message2 (failed 2 times in the last 0 minutes)")); + assertTrue(logCaptor.getErrorLogs().get(1).contains("Test Message3 (failed 1 times in the last 0 minutes)")); + assertTrue(logCaptorLocal.getWarnLogs().get(0).contains("Test Message (future failures will be aggregated and logged once every 0 minutes)")); + assertTrue(logCaptor.getWarnLogs().get(0).contains("3/4(Total Failures/Total Requests) reported in the last 0 minutes")); } } diff --git a/test/smoke/testApps/SpringCloudStream/src/smokeTest/java/com/microsoft/applicationinsights/smoketest/SpringCloudStreamTest.java b/test/smoke/testApps/SpringCloudStream/src/smokeTest/java/com/microsoft/applicationinsights/smoketest/SpringCloudStreamTest.java index 43ccfacde34..ef2f889ea37 100644 --- a/test/smoke/testApps/SpringCloudStream/src/smokeTest/java/com/microsoft/applicationinsights/smoketest/SpringCloudStreamTest.java +++ b/test/smoke/testApps/SpringCloudStream/src/smokeTest/java/com/microsoft/applicationinsights/smoketest/SpringCloudStreamTest.java @@ -59,9 +59,8 @@ public void doMostBasicTest() throws Exception { assertEquals("greetings", rd2.getSource()); assertEquals("greetings process", rd2.getName()); - assertParentChild(rd1.getId(), rdEnvelope1, rddEnvelope1); - assertParentChild(rdd1.getId(), rddEnvelope1, rddEnvelope2); - assertParentChild(rdd2.getId(), rddEnvelope2, rdEnvelope2); + assertParentChild(rdd1.getId(), rdEnvelope1, rddEnvelope2); + assertParentChild(rdd2.getId(), rddEnvelope1, rdEnvelope2); } private static void assertParentChild(String parentId, Envelope parentEnvelope, Envelope childEnvelope) { From 5a59bad9e534ce8c7fc82f0970d1abe718d3e446 Mon Sep 17 00:00:00 2001 From: kryalama <66494519+kryalama@users.noreply.github.com> Date: Wed, 24 Feb 2021 09:33:30 -0800 Subject: [PATCH 13/18] rename memoryexception to diskexception --- .../common/TransmissionFileSystemOutput.java | 22 +++++++++---------- 1 file changed, 11 insertions(+), 11 deletions(-) diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java index 5e20f28bc8b..69060900724 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java @@ -85,7 +85,7 @@ public final class TransmissionFileSystemOutput implements TransmissionOutputSyn private final static int MAX_CAPACITY_MEGABYTES = 1000; private final static int MIN_CAPACITY_MEGABYTES = 1; private static final String MAX_TRANSMISSION_STORAGE_CAPACITY_NAME = "Channel.MaxTransmissionStorageCapacityInMB"; - public static final ExceptionStats memoryExceptionStats = new ExceptionStats(); + public static final ExceptionStats diskExceptionStats = new ExceptionStats(); /// The folder in which we save transmission files @@ -142,7 +142,7 @@ public boolean sendSync(Transmission transmission) { long currentSizeInBytes = size.get(); if (currentSizeInBytes >= capacityInBytes) { - memoryExceptionStats.recordError("Persistent storage max capacity has been reached; " + diskExceptionStats.recordError("Persistent storage max capacity has been reached; " + "currently at "+ currentSizeInBytes +" bytes. Telemetry will be lost, " + "please consider increasing the value of MaxTransmissionStorageFilesCapacityInMB property in the configuration file.",logger); return false; @@ -162,7 +162,7 @@ public boolean sendSync(Transmission transmission) { } logger.debug("Data persisted to file. To be sent when the network is available."); - memoryExceptionStats.recordSuccess(); + diskExceptionStats.recordSuccess(); return true; } @@ -205,7 +205,7 @@ public Transmission fetchOldestFile() { } } } catch (Exception e) { - memoryExceptionStats.recordException("Error fetching oldest file", e, logger); + diskExceptionStats.recordException("Error fetching oldest file", e, logger); } return null; @@ -247,11 +247,11 @@ private Optional loadTransmission(File file) { try (ObjectInput input = new SafeObjectInputStream(new BufferedInputStream(new FileInputStream(file)))) { transmission = (Transmission)input.readObject(); } catch (FileNotFoundException e) { - memoryExceptionStats.recordException("Failed to load transmission, file not found", e, logger); + diskExceptionStats.recordException("Failed to load transmission, file not found", e, logger); } catch (ClassNotFoundException e) { - memoryExceptionStats.recordException("Failed to load transmission, non transmission", e, logger); + diskExceptionStats.recordException("Failed to load transmission, non transmission", e, logger); } catch (IOException e) { - memoryExceptionStats.recordException("Failed to load transmission, io exception", e, logger); + diskExceptionStats.recordException("Failed to load transmission, io exception", e, logger); } return Optional.fromNullable(transmission); @@ -280,7 +280,7 @@ private boolean renameToPermanentName(File tempTransmissionFile) { size.addAndGet(fileLength); return true; } catch (Exception e) { - memoryExceptionStats.recordException("Rename To Permanent Name failed", e, logger); + diskExceptionStats.recordException("Rename To Permanent Name failed", e, logger); } return false; @@ -294,7 +294,7 @@ private Optional renameToTemporaryName(File tempTransmissionFile) { size.addAndGet(-renamedFile.length()); transmissionFile = renamedFile; } catch (Exception ignore) { - memoryExceptionStats.recordException("Rename To Temporary Name failed", ignore, logger); + diskExceptionStats.recordException("Rename To Temporary Name failed", ignore, logger); // Consume the exception, since there isn't anything 'smart' to do now } @@ -307,7 +307,7 @@ private boolean saveTransmission(File transmissionFile, Transmission transmissio output.writeObject(transmission); return true; } catch (IOException e) { - memoryExceptionStats.recordException("Failed to save transmission", e, logger); + diskExceptionStats.recordException("Failed to save transmission", e, logger); } return false; @@ -319,7 +319,7 @@ private Optional createTemporaryFile() { String prefix = TRANSMISSION_FILE_PREFIX + "-" + System.currentTimeMillis() + "-"; file = File.createTempFile(prefix, null, folder); } catch (IOException e) { - memoryExceptionStats.recordException("Failed to create temporary file", e, logger); + diskExceptionStats.recordException("Failed to create temporary file", e, logger); } return Optional.fromNullable(file); From 63a5cc28860c39b64ac40cd4642ac84d6a4604d2 Mon Sep 17 00:00:00 2001 From: kryalama <66494519+kryalama@users.noreply.github.com> Date: Wed, 24 Feb 2021 14:18:49 -0800 Subject: [PATCH 14/18] changed the error message to lower cardinality --- .../com/microsoft/applicationinsights/common/CommonUtils.java | 2 -- .../internal/channel/common/TransmissionFileSystemOutput.java | 3 +-- 2 files changed, 1 insertion(+), 4 deletions(-) diff --git a/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java b/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java index dbb1453312d..58895ba01ad 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java +++ b/core/src/main/java/com/microsoft/applicationinsights/common/CommonUtils.java @@ -23,7 +23,6 @@ import java.net.InetAddress; import java.net.UnknownHostException; - import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -69,5 +68,4 @@ public static boolean isClassPresentOnClassPath(String classSignature, ClassLoad return false; } } - } diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java index 69060900724..337edbf5455 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java @@ -142,8 +142,7 @@ public boolean sendSync(Transmission transmission) { long currentSizeInBytes = size.get(); if (currentSizeInBytes >= capacityInBytes) { - diskExceptionStats.recordError("Persistent storage max capacity has been reached; " - + "currently at "+ currentSizeInBytes +" bytes. Telemetry will be lost, " + diskExceptionStats.recordError("Persistent storage max capacity of "+ capacityInBytes +" bytes has been reached. Telemetry will be lost, " + "please consider increasing the value of MaxTransmissionStorageFilesCapacityInMB property in the configuration file.",logger); return false; } From c91fe942d9c09843891bc60c61598dafbc4b8a3a Mon Sep 17 00:00:00 2001 From: Trask Stalnaker Date: Wed, 24 Feb 2021 21:02:51 -0800 Subject: [PATCH 15/18] Some last changes --- .../common/TransmissionFileSystemOutput.java | 28 ++++---- .../common/TransmissionNetworkOutput.java | 30 ++++---- .../internal/util/ExceptionStats.java | 68 +++++++++++-------- .../util/ExceptionStatsLoggerTest.java | 33 ++++----- 4 files changed, 82 insertions(+), 77 deletions(-) diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java index 337edbf5455..8873b1e882a 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java @@ -85,7 +85,12 @@ public final class TransmissionFileSystemOutput implements TransmissionOutputSyn private final static int MAX_CAPACITY_MEGABYTES = 1000; private final static int MIN_CAPACITY_MEGABYTES = 1; private static final String MAX_TRANSMISSION_STORAGE_CAPACITY_NAME = "Channel.MaxTransmissionStorageCapacityInMB"; - public static final ExceptionStats diskExceptionStats = new ExceptionStats(); + private static final ExceptionStats diskExceptionStats = new ExceptionStats( + TransmissionFileSystemOutput.class, + "Unable to send telemetry to the ingestion service," + + " and unable to store telemetry locally, so telemetry will be discarded." + + " See previous warning(s) for reason unable to send telemetry to the ingestion service." + + " Reason unable to store telemetry locally:"); /// The folder in which we save transmission files @@ -142,8 +147,7 @@ public boolean sendSync(Transmission transmission) { long currentSizeInBytes = size.get(); if (currentSizeInBytes >= capacityInBytes) { - diskExceptionStats.recordError("Persistent storage max capacity of "+ capacityInBytes +" bytes has been reached. Telemetry will be lost, " - + "please consider increasing the value of MaxTransmissionStorageFilesCapacityInMB property in the configuration file.",logger); + diskExceptionStats.recordFailure("local storage capacity (" + capacityInBytes / (1024 * 1024) + "MB) has been exceeded"); return false; } @@ -204,7 +208,7 @@ public Transmission fetchOldestFile() { } } } catch (Exception e) { - diskExceptionStats.recordException("Error fetching oldest file", e, logger); + logger.error("Error fetching oldest file", e); } return null; @@ -246,11 +250,11 @@ private Optional loadTransmission(File file) { try (ObjectInput input = new SafeObjectInputStream(new BufferedInputStream(new FileInputStream(file)))) { transmission = (Transmission)input.readObject(); } catch (FileNotFoundException e) { - diskExceptionStats.recordException("Failed to load transmission, file not found", e, logger); + logger.error("Failed to load transmission, file not found, exception: {}", e.toString()); } catch (ClassNotFoundException e) { - diskExceptionStats.recordException("Failed to load transmission, non transmission", e, logger); + logger.error("Failed to load transmission, non transmission, exception: {}", e.toString()); } catch (IOException e) { - diskExceptionStats.recordException("Failed to load transmission, io exception", e, logger); + logger.error("Failed to load transmission, io exception: {}", e.toString()); } return Optional.fromNullable(transmission); @@ -279,7 +283,7 @@ private boolean renameToPermanentName(File tempTransmissionFile) { size.addAndGet(fileLength); return true; } catch (Exception e) { - diskExceptionStats.recordException("Rename To Permanent Name failed", e, logger); + diskExceptionStats.recordFailure("unable to rename file to permanent name: " + e, e); } return false; @@ -292,8 +296,8 @@ private Optional renameToTemporaryName(File tempTransmissionFile) { FileUtils.moveFile(tempTransmissionFile, renamedFile); size.addAndGet(-renamedFile.length()); transmissionFile = renamedFile; - } catch (Exception ignore) { - diskExceptionStats.recordException("Rename To Temporary Name failed", ignore, logger); + } catch (Exception e) { + diskExceptionStats.recordFailure("unable to rename file to temporary name: " + e, e); // Consume the exception, since there isn't anything 'smart' to do now } @@ -306,7 +310,7 @@ private boolean saveTransmission(File transmissionFile, Transmission transmissio output.writeObject(transmission); return true; } catch (IOException e) { - diskExceptionStats.recordException("Failed to save transmission", e, logger); + diskExceptionStats.recordFailure("unable to write to file: " + e, e); } return false; @@ -318,7 +322,7 @@ private Optional createTemporaryFile() { String prefix = TRANSMISSION_FILE_PREFIX + "-" + System.currentTimeMillis() + "-"; file = File.createTempFile(prefix, null, folder); } catch (IOException e) { - diskExceptionStats.recordException("Failed to create temporary file", e, logger); + diskExceptionStats.recordFailure("unable to create temporary file: " + e, e); } return Optional.fromNullable(file); diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java index f3c3943de82..7e5a95ed387 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java @@ -59,12 +59,15 @@ public final class TransmissionNetworkOutput implements TransmissionOutputSync { private static final Logger logger = LoggerFactory.getLogger(TransmissionNetworkOutput.class); private static final AtomicBoolean friendlyExceptionThrown = new AtomicBoolean(); - public static final ExceptionStats networkExceptionStats = new ExceptionStats(); + private static final ExceptionStats networkExceptionStats = new ExceptionStats( + TransmissionNetworkOutput.class, + "Unable to send telemetry to the ingestion service," + + " so telemetry will be stored to disk and sent to the ingestion service later if possible." + + " Reason unable to send telemetry to the ingestion service:"); private static final String CONTENT_TYPE_HEADER = "Content-Type"; private static final String CONTENT_ENCODING_HEADER = "Content-Encoding"; private static final String RESPONSE_THROTTLING_HEADER = "Retry-After"; - private static final String TEMPORARY_EXCEPTION_MESSAGE = "Telemetry will be stored locally and re-sent later once the connection is stable again"; public static final String DEFAULT_SERVER_URI = "https://dc.services.visualstudio.com/v2/track"; @@ -182,34 +185,29 @@ public boolean sendSync(Transmission transmission) { } return true; } catch (ConnectionPoolTimeoutException e) { - networkExceptionStats.recordException( - "Failed to send, connection pool timeout exception. " + TEMPORARY_EXCEPTION_MESSAGE, e, logger); + networkExceptionStats.recordFailure("connection pool timeout exception: " + e, e); } catch (SocketException e) { - networkExceptionStats.recordException( - "Failed to send, socket exception. " + TEMPORARY_EXCEPTION_MESSAGE, e, logger); + networkExceptionStats.recordFailure("socket exception: " + e, e); } catch (SocketTimeoutException e) { - networkExceptionStats.recordException( - "Failed to send, socket timeout exception. " + TEMPORARY_EXCEPTION_MESSAGE, e, logger); + networkExceptionStats.recordFailure("socket timeout exception: " + e, e); } catch (UnknownHostException e) { - networkExceptionStats.recordException( - "Failed to send, wrong host address or cannot reach address due to network issues. " + TEMPORARY_EXCEPTION_MESSAGE, e, logger); + networkExceptionStats.recordFailure("wrong host address or cannot reach address due to network issues: " + e, e); } catch (IOException e) { - networkExceptionStats.recordException( - "Failed to send, IO exception. " + TEMPORARY_EXCEPTION_MESSAGE, e, logger); + networkExceptionStats.recordFailure("I/O exception: " + e, e); } catch (FriendlyException e) { ex = e; + // TODO should this be merged into networkExceptionStats? if(!friendlyExceptionThrown.getAndSet(true)) { logger.error(e.getMessage()); } } catch (Exception e) { - networkExceptionStats.recordException( - "Failed to send, unexpected exception. " + TEMPORARY_EXCEPTION_MESSAGE, e, logger); + networkExceptionStats.recordFailure("unexpected exception: " + e, e); } catch (ThreadDeath td) { throw td; } catch (Throwable t) { ex = t; try { - logger.error("Failed to send, unexpected error", t); + networkExceptionStats.recordFailure("unexpected exception: " + t, t); } catch (ThreadDeath td) { throw td; } catch (Throwable t2) { @@ -222,7 +220,7 @@ public boolean sendSync(Transmission transmission) { httpClient.dispose(response); if (code == HttpStatus.SC_BAD_REQUEST) { - networkExceptionStats.recordError("Error sending data: "+reason, logger); + networkExceptionStats.recordFailure("ingestion service returned 400 (" + reason + ")"); } else if (code != HttpStatus.SC_OK) { // Invoke the listeners for handling things like errors // The listeners will handle the back off logic as well as the dispatch diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java b/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java index 97e5174a171..7746d0208b6 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java @@ -6,9 +6,9 @@ import java.util.concurrent.ScheduledExecutorService; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicBoolean; -import java.util.concurrent.atomic.AtomicLong; -import com.microsoft.applicationinsights.internal.channel.common.TransmissionFileSystemOutput; +import javax.annotation.Nullable; + import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -20,7 +20,8 @@ public class ExceptionStats { private static final ScheduledExecutorService scheduledExecutor = Executors.newSingleThreadScheduledExecutor(ThreadPoolUtils.createDaemonThreadFactory(ExceptionStats.class, "exception stats logger")); - private static final Logger logger = LoggerFactory.getLogger(ExceptionStats.class); + private final Logger logger; + private final String introMessage; // Period for scheduled executor in secs private final int intervalSeconds; @@ -40,12 +41,14 @@ public class ExceptionStats { private final Object lock = new Object(); - public ExceptionStats() { - this(300); + public ExceptionStats(Class source, String introMessage) { + this(source, introMessage, 300); } // Primarily used by test - public ExceptionStats(int intervalSeconds) { + public ExceptionStats(Class source, String introMessage, int intervalSeconds) { + logger = LoggerFactory.getLogger(source); + this.introMessage = introMessage; this.intervalSeconds = intervalSeconds; } @@ -56,32 +59,25 @@ public void recordSuccess() { } // warningMessage should have low cardinality - public void recordException(String warningMessage, Exception exception, Logger logger) { - if (!firstFailure.getAndSet(true)) { - // log the first time we see an exception as soon as it occurs - logger.warn(warningMessage + " (future failures will be aggregated and logged once every "+ this.intervalSeconds /60 +" minutes)", exception); - scheduledExecutor.scheduleAtFixedRate(new ExceptionStatsLogger(), intervalSeconds, intervalSeconds, TimeUnit.SECONDS); - return; - } - - logger.debug(warningMessage, exception); - - synchronized (lock) { - warningMessages.computeIfAbsent(warningMessage, key -> new MutableLong()).increment(); - numFailures++; - } + public void recordFailure(String warningMessage) { + recordFailure(warningMessage, null); } - public void recordError(String warningMessage, Logger logger) { + // warningMessage should have low cardinality + public void recordFailure(String warningMessage, @Nullable Throwable exception) { if (!firstFailure.getAndSet(true)) { - // log the first time we see an exception as soon as it occurs - logger.warn(warningMessage + " (future failures will be aggregated and logged once every "+ this.intervalSeconds /60 +" minutes)"); + // log the first time we see an exception as soon as it occurs, along with full stack trace + logger.warn(introMessage + " " + warningMessage + " (future failures will be aggregated and logged once every " + intervalSeconds / 60 + " minutes)", exception); scheduledExecutor.scheduleAtFixedRate(new ExceptionStatsLogger(), intervalSeconds, intervalSeconds, TimeUnit.SECONDS); return; } - logger.debug(warningMessage); + logger.debug(introMessage + " " + warningMessage, exception); + if (warningMessages.size() > 100) { + // we have a cardinality problem and don't want to consume too much memory or do too much logging + return; + } synchronized (lock) { warningMessages.computeIfAbsent(warningMessage, key -> new MutableLong()).increment(); numFailures++; @@ -113,11 +109,25 @@ public void run() { ExceptionStats.this.warningMessages = new HashMap<>(); } if (numFailures > 0) { - warningMessages.forEach( - (message,failureCount) -> logger.error(message+" (failed "+ failureCount.value + " times in the last "+ ExceptionStats.this.intervalSeconds/60 +" minutes)") - ); - logger.warn(numFailures+"/"+(numFailures+numSuccesses) + "(Total Failures/Total Requests) reported in the last "+ ExceptionStats.this.intervalSeconds/60 +" minutes"); - + long numMinutes = ExceptionStats.this.intervalSeconds / 60; + long total = numSuccesses + numFailures; + StringBuilder message = new StringBuilder(); + message.append("In the last "); + message.append(numMinutes); + message.append(" minutes, the following operation has failed "); + message.append(numFailures); + message.append(" times (out of "); + message.append(total); + message.append(" total):\n"); + message.append(introMessage); + for (Map.Entry entry : warningMessages.entrySet()) { + message.append("\n * "); + message.append(entry.getKey()); + message.append(" ("); + message.append(entry.getValue().value); + message.append(" times)"); + } + logger.warn(message.toString()); } } } diff --git a/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java b/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java index 8cd5f37b36c..54bc16aab28 100644 --- a/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java +++ b/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java @@ -2,41 +2,34 @@ import nl.altindag.log.LogCaptor; import org.junit.*; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; import static org.junit.Assert.*; public class ExceptionStatsLoggerTest { private static ExceptionStats networkExceptionStats; - private static Logger logger; @BeforeClass public static void setUp() { // one-time initialization code - networkExceptionStats = new ExceptionStats(3); - logger = LoggerFactory.getLogger(ExceptionStatsLoggerTest.class); + networkExceptionStats = new ExceptionStats(ExceptionStatsLoggerTest.class, "intro:", 1); } @Test public void testWarnAndExceptionsAreLogged() throws InterruptedException { - LogCaptor logCaptorLocal = LogCaptor.forClass(ExceptionStatsLoggerTest.class); - LogCaptor logCaptor = LogCaptor.forClass(ExceptionStats.class); + LogCaptor logCaptor = LogCaptor.forClass(ExceptionStatsLoggerTest.class); networkExceptionStats.recordSuccess(); Exception ex=new IllegalArgumentException(); - networkExceptionStats.recordException("Test Message",ex,logger); - networkExceptionStats.recordException("Test Message2",ex,logger); - networkExceptionStats.recordException("Test Message2",ex,logger); - networkExceptionStats.recordException("Test Message3",ex,logger); - //wait for 3 secs + networkExceptionStats.recordFailure("Test Message",ex); + networkExceptionStats.recordFailure("Test Message2",ex); + networkExceptionStats.recordFailure("Test Message2",ex); + networkExceptionStats.recordFailure("Test Message3",ex); + //wait for more than 1 second Thread.sleep(3000); - assertEquals(2,logCaptor.getErrorLogs().size()); - assertEquals(1,logCaptor.getWarnLogs().size()); - System.out.println(logCaptor.getWarnLogs()); - assertTrue(logCaptor.getErrorLogs().get(0).contains("Test Message2 (failed 2 times in the last 0 minutes)")); - assertTrue(logCaptor.getErrorLogs().get(1).contains("Test Message3 (failed 1 times in the last 0 minutes)")); - assertTrue(logCaptorLocal.getWarnLogs().get(0).contains("Test Message (future failures will be aggregated and logged once every 0 minutes)")); - assertTrue(logCaptor.getWarnLogs().get(0).contains("3/4(Total Failures/Total Requests) reported in the last 0 minutes")); + assertEquals(2,logCaptor.getWarnLogs().size()); + assertTrue(logCaptor.getWarnLogs().get(0).contains("intro: Test Message (future failures will be aggregated and logged once every 0 minutes)")); + assertTrue(logCaptor.getWarnLogs().get(1).contains("In the last 0 minutes, the following operation has failed 3 times (out of 4 total):\n" + + "intro:\n" + + " * Test Message2 (2 times)\n" + + " * Test Message3 (1 times)")); } - } From 512c563fd70fb10e49fe65fca9e1cea4a6ef2ca1 Mon Sep 17 00:00:00 2001 From: Trask Stalnaker Date: Thu, 25 Feb 2021 13:55:35 -0800 Subject: [PATCH 16/18] Simplify messages --- .../channel/common/TransmissionFileSystemOutput.java | 6 +----- .../internal/channel/common/TransmissionNetworkOutput.java | 4 +--- .../applicationinsights/internal/util/ExceptionStats.java | 2 +- 3 files changed, 3 insertions(+), 9 deletions(-) diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java index 8873b1e882a..3ba02833a63 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java @@ -87,11 +87,7 @@ public final class TransmissionFileSystemOutput implements TransmissionOutputSyn private static final String MAX_TRANSMISSION_STORAGE_CAPACITY_NAME = "Channel.MaxTransmissionStorageCapacityInMB"; private static final ExceptionStats diskExceptionStats = new ExceptionStats( TransmissionFileSystemOutput.class, - "Unable to send telemetry to the ingestion service," + - " and unable to store telemetry locally, so telemetry will be discarded." + - " See previous warning(s) for reason unable to send telemetry to the ingestion service." + - " Reason unable to store telemetry locally:"); - + "Unable to store telemetry to disk (telemetry will be discarded):"); /// The folder in which we save transmission files private File folder; diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java index 7e5a95ed387..dd95ce9b73e 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionNetworkOutput.java @@ -61,9 +61,7 @@ public final class TransmissionNetworkOutput implements TransmissionOutputSync { private static final AtomicBoolean friendlyExceptionThrown = new AtomicBoolean(); private static final ExceptionStats networkExceptionStats = new ExceptionStats( TransmissionNetworkOutput.class, - "Unable to send telemetry to the ingestion service," + - " so telemetry will be stored to disk and sent to the ingestion service later if possible." + - " Reason unable to send telemetry to the ingestion service:"); + "Unable to send telemetry to the ingestion service (telemetry will be stored to disk):"); private static final String CONTENT_TYPE_HEADER = "Content-Type"; private static final String CONTENT_ENCODING_HEADER = "Content-Encoding"; diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java b/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java index 7746d0208b6..0c6bf97d4fc 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/util/ExceptionStats.java @@ -118,7 +118,7 @@ public void run() { message.append(numFailures); message.append(" times (out of "); message.append(total); - message.append(" total):\n"); + message.append("):\n"); message.append(introMessage); for (Map.Entry entry : warningMessages.entrySet()) { message.append("\n * "); From f98104898e6b2962f92fb08976a211cbf1a90ce0 Mon Sep 17 00:00:00 2001 From: Trask Stalnaker Date: Thu, 25 Feb 2021 14:00:35 -0800 Subject: [PATCH 17/18] Remove message that's not part of saving to disk --- .../internal/channel/common/TransmissionFileSystemOutput.java | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java index 3ba02833a63..fc2c4814b65 100644 --- a/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java +++ b/core/src/main/java/com/microsoft/applicationinsights/internal/channel/common/TransmissionFileSystemOutput.java @@ -292,8 +292,8 @@ private Optional renameToTemporaryName(File tempTransmissionFile) { FileUtils.moveFile(tempTransmissionFile, renamedFile); size.addAndGet(-renamedFile.length()); transmissionFile = renamedFile; - } catch (Exception e) { - diskExceptionStats.recordFailure("unable to rename file to temporary name: " + e, e); + } catch (Exception ignore) { + logger.error("Rename To Temporary Name failed, exception: {}", ignore.toString()); // Consume the exception, since there isn't anything 'smart' to do now } From 608c9dbec5013431b5ec272e02a9608d723dc2e7 Mon Sep 17 00:00:00 2001 From: kryalama <66494519+kryalama@users.noreply.github.com> Date: Thu, 25 Feb 2021 14:33:12 -0800 Subject: [PATCH 18/18] fixed unit test --- .../internal/util/ExceptionStatsLoggerTest.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java b/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java index 54bc16aab28..84995993deb 100644 --- a/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java +++ b/core/src/test/java/com/microsoft/applicationinsights/internal/util/ExceptionStatsLoggerTest.java @@ -27,7 +27,7 @@ public void testWarnAndExceptionsAreLogged() throws InterruptedException { Thread.sleep(3000); assertEquals(2,logCaptor.getWarnLogs().size()); assertTrue(logCaptor.getWarnLogs().get(0).contains("intro: Test Message (future failures will be aggregated and logged once every 0 minutes)")); - assertTrue(logCaptor.getWarnLogs().get(1).contains("In the last 0 minutes, the following operation has failed 3 times (out of 4 total):\n" + + assertTrue(logCaptor.getWarnLogs().get(1).contains("In the last 0 minutes, the following operation has failed 3 times (out of 4):\n" + "intro:\n" + " * Test Message2 (2 times)\n" + " * Test Message3 (1 times)"));