java - 将 Logback 跟踪日志发送到 Azure 应用程序洞察 - 错误 : failed to send, 错误请求

Question

我在 Azure 中有一个 Java Web 应用程序，它使用 Logback 进行跟踪日志记录。我正在尝试将跟踪日志记录链接到 Azure 中的 Application Insights，并且我已按照 Azure documentation 中的所有说明进行操作。 .

这是 Maven pom.xml 的相关部分:

    <dependency>
        <groupId>com.microsoft.azure</groupId>
        <artifactId>applicationinsights-web</artifactId>
        <version>[1.0,)</version>
    </dependency>
    <dependency>
        <groupId>com.microsoft.azure</groupId>
        <artifactId>applicationinsights-core</artifactId>
        <version>[1.0,)</version>
    </dependency>
    <dependency>
        <groupId>com.microsoft.azure</groupId>
        <artifactId>applicationinsights-logging-logback</artifactId>
        <version>[1.0,)</version>
    </dependency>
  </dependencies>

  <repositories>
    <repository>
      <id>central</id>
      <name>Central</name>
      <url>http://repo1.maven.org/maven2</url>
    </repository>
  </repositories>

我的ApplicationInsights.xml:

<?xml version="1.0" encoding="utf-8" standalone="no"?>
<!DOCTYPE xml>
<ApplicationInsights xmlns="http://schemas.microsoft.com/ApplicationInsights/2013/Settings" schemaVersion="2014-05-30">
  <SDKLogger />
  <InstrumentationKey>*my key here*</InstrumentationKey>
  <ContextInitializers>
  </ContextInitializers>
  <TelemetryInitializers>
    <Add type="com.microsoft.applicationinsights.web.extensibility.initializers.WebOperationIdTelemetryInitializer"/>
    <Add type="com.microsoft.applicationinsights.web.extensibility.initializers.WebOperationNameTelemetryInitializer"/>
    <Add type="com.microsoft.applicationinsights.web.extensibility.initializers.WebSessionTelemetryInitializer"/>
    <Add type="com.microsoft.applicationinsights.web.extensibility.initializers.WebUserTelemetryInitializer"/>
    <Add type="com.microsoft.applicationinsights.web.extensibility.initializers.WebUserAgentTelemetryInitializer"/>
  </TelemetryInitializers>
  <TelemetryModules>
    <Add type="com.microsoft.applicationinsights.web.extensibility.modules.WebRequestTrackingTelemetryModule"/>
    <Add type="com.microsoft.applicationinsights.web.extensibility.modules.WebSessionTrackingTelemetryModule"/>
    <Add type="com.microsoft.applicationinsights.web.extensibility.modules.WebUserTrackingTelemetryModule"/>    
  </TelemetryModules>
  <Channel>
    <!-- 
      Setting DeveloperMode to true will enable immediate transmission of the telemetry events, which can be helpful during the development process.
      Make sure to turn this off on production servers due to performance considerations.
    -->
    <DeveloperMode>true</DeveloperMode>
  </Channel>
  <DisableTelemetry>false</DisableTelemetry>
</ApplicationInsights>

我的logback.xml:

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE xml>

<configuration debug = "true">

    <appender class="ch.qos.logback.core.ConsoleAppender" name="STDOUT">
        <encoder>
            <Pattern>%d{HH:mm:ss.SSS} %-5level - %msg%n</Pattern>
        </encoder>
    </appender>

    <appender name="aiAppender" class="com.microsoft.applicationinsights.logback.ApplicationInsightsAppender">
    </appender>

    <root level="info">
        <appender-ref ref="STDOUT"/>
        <appender-ref ref="aiAppender"/>
    </root>

</configuration>

我的类测试记录器和应用程序洞察集成:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import com.microsoft.applicationinsights.TelemetryClient;
/**
 * Hello world!
 *
 */
public class App 
{
    private final static Logger LOG = LoggerFactory.getLogger("root");
    public static void main( String[] args ) throws InterruptedException
    {
        LOG.info("Logging is working");
        TelemetryClient tc = new TelemetryClient();
        tc.trackTrace("Telemetry is working");
        System.out.println( "Hello World!" );
    }
}

当我运行此命令时，Logback 可以与控制台附加程序一起正常工作，对应用程序见解的遥测工作正常，但跟踪日志不会进入应用程序见解门户。我收到以下错误:

AI: ERROR 18-10-2017 20:40, 19: Failed to send, Bad request : {"itemsReceived":1,"itemsAccepted":0,"errors":[{"index":0,"statusCode":400,"message":"SyntaxError: Unexpected token I"}]}

我一直在寻找解决这个问题的方法，但似乎无法解决。有人有什么想法吗？谢谢!!

更新:

这是完整的堆栈跟踪:

09:13:59,774 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
09:13:59,774 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
09:13:59,774 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/C:/Users/greta/OneDrive/Eclipse%20Water%20Application%20Project%20Files/Test2/target/classes/logback.xml]
09:13:59,888 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
09:13:59,891 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
09:13:59,911 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
09:13:59,943 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [com.microsoft.applicationinsights.logback.ApplicationInsightsAppender]
09:13:59,988 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [aiAppender]
AI: INFO 20-10-2017 09:14, 1: Configuration file has been successfully found as resource
AI: INFO 20-10-2017 09:14, 1: 'MaxTelemetryBufferCapacity': null value is replaced with '500'
AI: INFO 20-10-2017 09:14, 1: 'FlushIntervalInSeconds': null value is replaced with '5'
AI: TRACE 20-10-2017 09:14, 1: Using Http Client version 4.3+
AI: INFO 20-10-2017 09:14, 1: 'Channel.MaxTransmissionStorageCapacityInMB': null value is replaced with '10'
AI: TRACE 20-10-2017 09:14, 1: C:\Users\greta\AppData\Local\Temp\AISDK\native\1.0.10 folder exists
AI: TRACE 20-10-2017 09:14, 1: Java process name is set to 'javaw'
AI: TRACE 20-10-2017 09:14, 1: Successfully loaded library 'applicationinsights-core-native-win64.dll'
AI: INFO 20-10-2017 09:14, 1: Configuration file has been successfully found as resource
AI: INFO 20-10-2017 09:14, 1: 'MaxTelemetryBufferCapacity': null value is replaced with '500'
AI: INFO 20-10-2017 09:14, 1: 'FlushIntervalInSeconds': null value is replaced with '5'
AI: INFO 20-10-2017 09:14, 1: 'Channel.MaxTransmissionStorageCapacityInMB': null value is replaced with '10'
AI: TRACE 20-10-2017 09:14, 1: C:\Users\greta\AppData\Local\Temp\AISDK\native\1.0.10 folder exists
AI: TRACE 20-10-2017 09:14, 1: Java process name is set to 'javaw'
AI: TRACE 20-10-2017 09:14, 1: Successfully loaded library 'applicationinsights-core-native-win64.dll'
AI: TRACE 20-10-2017 09:14, 1: Registering PC 'DeadLockDetector'
AI: TRACE 20-10-2017 09:14, 1: Registering PC 'JvmHeapMemoryUsedPerformanceCounter'
AI: TRACE 20-10-2017 09:14, 1: Registering PC 'JSDK_ProcessMemoryPerformanceCounter'
AI: TRACE 20-10-2017 09:14, 1: Registering PC 'JSDK_ProcessCpuPerformanceCounter'
AI: TRACE 20-10-2017 09:14, 1: Registering PC 'JSDK_WindowsPerformanceCounterAsPC'
AI: TRACE 20-10-2017 09:14, 1: Registering PC 'DeadLockDetector'
AI: TRACE 20-10-2017 09:14, 1: Failed to store performance counter 'DeadLockDetector', since there is already one
AI: TRACE 20-10-2017 09:14, 1: Registering PC 'JvmHeapMemoryUsedPerformanceCounter'
AI: TRACE 20-10-2017 09:14, 1: Failed to store performance counter 'JvmHeapMemoryUsedPerformanceCounter', since there is already one
AI: ERROR 20-10-2017 09:14, 1: Failed to create WindowsPerformanceCounterAsPC: 'Failed to register all built-in Windows performance counters.'
AI: TRACE 20-10-2017 09:14, 1: Registering PC 'JSDK_ProcessMemoryPerformanceCounter'
AI: TRACE 20-10-2017 09:14, 1: Failed to store performance counter 'JSDK_ProcessMemoryPerformanceCounter', since there is already one
AI: TRACE 20-10-2017 09:14, 1: Registering PC 'JSDK_ProcessCpuPerformanceCounter'
AI: TRACE 20-10-2017 09:14, 1: Failed to store performance counter 'JSDK_ProcessCpuPerformanceCounter', since there is already one
09:14:01,943 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
09:14:01,943 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
09:14:01,944 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [aiAppender] to Logger[ROOT]
09:14:01,944 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
09:14:01,945 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@6b415f5f - Registering current configuration as safe fallback point
09:13:59,774 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
09:13:59,774 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
09:13:59,774 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/C:/Users/greta/OneDrive/Eclipse%20Water%20Application%20Project%20Files/Test2/target/classes/logback.xml]
09:13:59,888 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
09:13:59,891 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
09:13:59,911 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
09:13:59,943 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [com.microsoft.applicationinsights.logback.ApplicationInsightsAppender]
09:13:59,988 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [aiAppender]
09:14:01,943 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
09:14:01,943 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
09:14:01,944 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [aiAppender] to Logger[ROOT]
09:14:01,944 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
09:14:01,945 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@6b415f5f - Registering current configuration as safe fallback point
09:14:01.948 INFO - Logging is working
AI: TRACE 20-10-2017 09:14, 1: InProcessTelemetryChannel sending telemetry
AI: TRACE 20-10-2017 09:14, 1: InProcessTelemetryChannel sending telemetry
Hello World!
AI: ERROR 20-10-2017 09:14, 19: Failed to send, Bad request : {"itemsReceived":1,"itemsAccepted":0,"errors":[{"index":0,"statusCode":400,"message":"SyntaxError: Unexpected token I"}]}

存在一些与性能计数器相关的错误。我尝试查找有关这些错误的一些信息，但运气不佳。也许这就是问题的一部分？

Answer 1

我在这里看到的问题之一是 AI 的内部记录器正在报告意外的字符。我发现可能的问题之一是清理逻辑中存在一些问题，导致项目无法发送到端点，因此您无法在门户上看到数据。另外还有一些已知的 logback 问题，这些问题已经在 github 上提到过: https://github.com/Microsoft/ApplicationInsights-Java/issues/453这应该可以回答你的问题。如果您愿意，请随时在 Github 上创建另一个问题。希望下一个公开版本能够解决这个问题。