STDOUT All Functions Diagnostics Logs (#2108) (#2264)

* Enable etw and status file on function

* Fix spotless

* Add debugging logs

* Fix npe

* Use sout

* Update version number

* Fix spotless

* Fix spotless

* Fix spotless

* Remove it

* Update codeowners

* Set diagnostics logger to debug level

* Add console appender to diagnostic logger

* Revert previous change

* Cleanup stdout

* More cleanup

* Use console on linux consumption plan only

* Use csv format as the linux diagnostic logging

* Fix spotlessApply

* Suppress stdout

* Add prefix

* Update prefix and add newline

* Clean up logs

* Remove suppressWarning for stdout

* Fix sdkVersion with prefix

* Don't write functions logs to json file

* Refactor

* Fix errorProne

* Address feedback

* Add a todo

Co-authored-by: Helen <[email protected]>

Author: trask

agent/agent-bootstrap/src/main/java/com/microsoft/applicationinsights/agent/bootstrap/diagnostics/DiagnosticsHelper.java

@@ -53,6 +53,7 @@ private DiagnosticsHelper() {}
 
   public static void setAgentJarFile(Path agentPath) {
     if (Files.exists(agentPath.resolveSibling("appsvc.codeless"))) {
+      // TODO we can remove this check after the new functions model is deployed.
       if ("java".equals(System.getenv("FUNCTIONS_WORKER_RUNTIME"))) {
         rpIntegrationChar = 'f';
       } else {

agent/agent-bootstrap/src/main/java/com/microsoft/applicationinsights/agent/bootstrap/diagnostics/etw/EtwAppender.java

@@ -54,7 +54,7 @@ public EtwAppender() {
   @Override
   public void start() {
     IpaVerbose event = new IpaVerbose(proto);
-    event.setMessageFormat("EtwProvider initialized sucessfully.");
+    event.setMessageFormat("EtwProvider initialized successfully.");
     try {
       this.etwProvider.writeEvent(event);
     } catch (LinkageError | ApplicationInsightsEtwException e) {

agent/agent-bootstrap/src/main/java/com/microsoft/applicationinsights/agent/bootstrap/diagnostics/log/ApplicationInsightsCsvLayout.java

@@ -0,0 +1,67 @@
+/*
+ * ApplicationInsights-Java
+ * Copyright (c) Microsoft Corporation
+ * All rights reserved.
+ *
+ * MIT License
+ * Permission is hereby granted, free of charge, to any person obtaining a copy of this
+ * software and associated documentation files (the ""Software""), to deal in the Software
+ * without restriction, including without limitation the rights to use, copy, modify, merge,
+ * publish, distribute, sublicense, and/or sell copies of the Software, and to permit
+ * persons to whom the Software is furnished to do so, subject to the following conditions:
+ * The above copyright notice and this permission notice shall be included in all copies or
+ * substantial portions of the Software.
+ * THE SOFTWARE IS PROVIDED *AS IS*, WITHOUT WARRANTY OF ANY KIND, EXPRESS OR IMPLIED,
+ * INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, FITNESS FOR A PARTICULAR
+ * PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE
+ * FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR
+ * OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER
+ * DEALINGS IN THE SOFTWARE.
+ */
+
+package com.microsoft.applicationinsights.agent.bootstrap.diagnostics.log;
+
+import ch.qos.logback.classic.PatternLayout;
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import com.microsoft.applicationinsights.agent.bootstrap.diagnostics.ApplicationMetadataFactory;
+import com.microsoft.applicationinsights.agent.bootstrap.diagnostics.DiagnosticsHelper;
+
+public class ApplicationInsightsCsvLayout extends PatternLayout {
+
+  private static final String PREFIX = "LanguageWorkerConsoleLogMS_APPLICATION_INSIGHTS_LOGS";
+
+  private static final ApplicationMetadataFactory applicationMetadataFactory =
+      DiagnosticsHelper.getMetadataFactory();
+  private final String qualifiedSdkVersion;
+
+  public ApplicationInsightsCsvLayout(String qualifiedSdkVersion) {
+    this.qualifiedSdkVersion = qualifiedSdkVersion;
+  }
+
+  @Override
+  public String doLayout(ILoggingEvent event) {
+    StringBuilder stringBuilder = new StringBuilder();
+    stringBuilder.append(PREFIX);
+    stringBuilder.append(" ");
+    stringBuilder.append(event.getTimeStamp());
+    stringBuilder.append(",");
+    stringBuilder.append(event.getLevel().toString());
+    stringBuilder.append(",");
+    stringBuilder.append(event.getLoggerName());
+    stringBuilder.append(",");
+    stringBuilder.append("\"");
+    stringBuilder.append(event.getFormattedMessage());
+    stringBuilder.append("\"");
+    stringBuilder.append(",");
+    stringBuilder.append(applicationMetadataFactory.getSiteName().getValue());
+    stringBuilder.append(",");
+    stringBuilder.append(applicationMetadataFactory.getInstrumentationKey().getValue());
+    stringBuilder.append(",");
+    stringBuilder.append(qualifiedSdkVersion);
+    stringBuilder.append(",");
+    stringBuilder.append("java");
+    stringBuilder.append(System.getProperty("line.separator"));
+
+    return stringBuilder.toString();
+  }
+}

agent/agent-bootstrap/src/main/java/com/microsoft/applicationinsights/agent/bootstrap/diagnostics/status/StatusFile.java

@@ -154,6 +154,7 @@ private static boolean shouldWrite() {
     if (writable) {
       return true;
     }
+
     // read-only app services, want to log warning once in this case
     if (startupLogger != null && !alreadyLogged.getAndSet(true)) {
       startupLogger.info(

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

@@ -24,10 +24,8 @@
 import com.azure.monitor.opentelemetry.exporter.implementation.utils.Strings;
 import com.azure.monitor.opentelemetry.exporter.implementation.utils.TempDirs;
 import com.microsoft.applicationinsights.agent.bootstrap.BytecodeUtil;
-import com.microsoft.applicationinsights.agent.bootstrap.diagnostics.DiagnosticsHelper;
 import com.microsoft.applicationinsights.agent.bootstrap.diagnostics.SdkVersionFinder;
 import com.microsoft.applicationinsights.agent.internal.common.FriendlyException;
-import com.microsoft.applicationinsights.agent.internal.common.PropertyHelper;
 import com.microsoft.applicationinsights.agent.internal.common.SystemInformation;
 import com.microsoft.applicationinsights.agent.internal.configuration.Configuration;
 import com.microsoft.applicationinsights.agent.internal.configuration.Configuration.ProfilerConfiguration;
@@ -56,7 +54,6 @@
 import java.net.URL;
 import java.util.List;
 import java.util.stream.Collectors;
-import org.checkerframework.checker.nullness.qual.Nullable;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
@@ -85,11 +82,6 @@ static AppIdSupplier beforeAgent(Instrumentation instrumentation) {
 
   private static AppIdSupplier start() {
 
-    String codelessSdkNamePrefix = getCodelessSdkNamePrefix();
-    if (codelessSdkNamePrefix != null) {
-      PropertyHelper.setSdkNamePrefix(codelessSdkNamePrefix);
-    }
-
     File tempDir =
         TempDirs.getApplicationInsightsTempDir(
             startupLogger,
@@ -212,25 +204,6 @@ private static ServiceProfilerServiceConfig formServiceProfilerConfig(
         TempDirs.getSubDir(tempDir, "profiles"));
   }
 
-  @Nullable
-  private static String getCodelessSdkNamePrefix() {
-    if (!DiagnosticsHelper.isRpIntegration()) {
-      return null;
-    }
-    StringBuilder sdkNamePrefix = new StringBuilder(4);
-    sdkNamePrefix.append(DiagnosticsHelper.rpIntegrationChar());
-    if (SystemInformation.isWindows()) {
-      sdkNamePrefix.append("w");
-    } else if (SystemInformation.isLinux()) {
-      sdkNamePrefix.append("l");
-    } else {
-      startupLogger.warn("could not detect os: {}", System.getProperty("os.name"));
-      sdkNamePrefix.append("u");
-    }
-    sdkNamePrefix.append("r_"); // "r" is for "recommended"
-    return sdkNamePrefix.toString();
-  }
-
   private static boolean hasConnectionString(Configuration config) {
     return !Strings.isNullOrEmpty(config.connectionString);
   }

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

@@ -38,9 +38,11 @@
 import ch.qos.logback.core.util.FileSize;
 import com.microsoft.applicationinsights.agent.bootstrap.diagnostics.DiagnosticsHelper;
 import com.microsoft.applicationinsights.agent.bootstrap.diagnostics.etw.EtwAppender;
+import com.microsoft.applicationinsights.agent.bootstrap.diagnostics.log.ApplicationInsightsCsvLayout;
 import com.microsoft.applicationinsights.agent.bootstrap.diagnostics.log.ApplicationInsightsDiagnosticsLogFilter;
 import com.microsoft.applicationinsights.agent.bootstrap.diagnostics.log.ApplicationInsightsJsonLayout;
 import com.microsoft.applicationinsights.agent.bootstrap.diagnostics.log.MoshiJsonFormatter;
+import com.microsoft.applicationinsights.agent.internal.common.PropertyHelper;
 import com.microsoft.applicationinsights.agent.internal.configuration.Configuration;
 import com.microsoft.applicationinsights.agent.internal.logbackpatch.FixedWindowRollingPolicy;
 import java.nio.file.Path;
@@ -73,7 +75,9 @@ void configure() {
     loggerContext.getLogger(ROOT_LOGGER_NAME).detachAndStopAllAppenders();
 
     if (DiagnosticsHelper.useAppSvcRpIntegrationLogging()) {
-      configureAppSvcs();
+      configureAppSvc();
+    } else if (DiagnosticsHelper.useFunctionsRpIntegrationLogging()) {
+      configureFunctions();
     } else if (destination == null || destination.equalsIgnoreCase("file+console")) {
       configureFileAndConsole();
     } else if (destination.equalsIgnoreCase("file")) {
@@ -85,7 +89,7 @@ void configure() {
     }
   }
 
-  private void configureAppSvcs() {
+  private void configureAppSvc() {
     Logger rootLogger = loggerContext.getLogger(ROOT_LOGGER_NAME);
     rootLogger.addAppender(configureFileAppender());
     rootLogger.addAppender(configureConsoleAppender());
@@ -124,11 +128,26 @@ private void configureAppSvcs() {
     loggingLevelConfigurator.initLoggerLevels(loggerContext);
   }
 
+  private void configureFunctions() {
+    Logger rootLogger = loggerContext.getLogger(ROOT_LOGGER_NAME);
+    rootLogger.addAppender(configureConsoleAppender());
+    Logger diagnosticLogger = loggerContext.getLogger(DiagnosticsHelper.DIAGNOSTICS_LOGGER_NAME);
+    diagnosticLogger.setLevel(Level.INFO);
+    diagnosticLogger.setAdditive(false);
+    Appender<ILoggingEvent> appender = configureConsoleAppender();
+    diagnosticLogger.addAppender(appender);
+
+    // errors reported by other loggers should also go to diagnostic log
+    // (level filter for these is applied in ApplicationInsightsDiagnosticsLogFilter)
+    rootLogger.addAppender(appender);
+
+    loggingLevelConfigurator.initLoggerLevels(loggerContext);
+  }
+
   private void configureFileAndConsole() {
     Logger rootLogger = loggerContext.getLogger(ROOT_LOGGER_NAME);
     rootLogger.addAppender(configureFileAppender());
     rootLogger.addAppender(configureConsoleAppender());
-
     loggingLevelConfigurator.initLoggerLevels(loggerContext);
     // these messages are specifically designed for attach
     loggerContext.getLogger("applicationinsights.extension.diagnostics").setLevel(Level.OFF);
@@ -200,7 +219,13 @@ private Appender<ILoggingEvent> configureConsoleAppender() {
     appender.setContext(loggerContext);
     appender.setName("CONSOLE");
 
-    appender.setEncoder(createEncoder());
+    // format Functions diagnostic log as comma separated
+    if (DiagnosticsHelper.useFunctionsRpIntegrationLogging()) {
+      appender.setLayout(
+          new ApplicationInsightsCsvLayout(PropertyHelper.getQualifiedSdkVersionString()));
+    } else {
+      appender.setEncoder(createEncoder());
+    }
     appender.start();
 
     return appender;

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

@@ -26,6 +26,8 @@
 import com.microsoft.applicationinsights.agent.bootstrap.diagnostics.SdkVersionFinder;
 import com.microsoft.applicationinsights.agent.bootstrap.diagnostics.status.StatusFile;
 import com.microsoft.applicationinsights.agent.internal.common.FriendlyException;
+import com.microsoft.applicationinsights.agent.internal.common.PropertyHelper;
+import com.microsoft.applicationinsights.agent.internal.common.SystemInformation;
 import com.microsoft.applicationinsights.agent.internal.configuration.Configuration;
 import com.microsoft.applicationinsights.agent.internal.configuration.Configuration.SelfDiagnostics;
 import com.microsoft.applicationinsights.agent.internal.configuration.ConfigurationBuilder;
@@ -88,6 +90,11 @@ public static void start(Instrumentation instrumentation, File javaagentFile) {
       // configuration is only read this early in order to extract logging configuration
       rpConfiguration = RpConfigurationBuilder.create(agentPath);
       configuration = ConfigurationBuilder.create(agentPath, rpConfiguration);
+
+      String codelessSdkNamePrefix = getCodelessSdkNamePrefix();
+      if (codelessSdkNamePrefix != null) {
+        PropertyHelper.setSdkNamePrefix(codelessSdkNamePrefix);
+      }
       startupLogger = configureLogging(configuration.selfDiagnostics, agentPath);
       StatusFile.startupLogger = startupLogger;
       ConfigurationBuilder.logConfigurationWarnMessages();
@@ -214,4 +221,24 @@ private static Logger configureLogging(SelfDiagnostics selfDiagnostics, Path age
     new LoggingConfigurator(selfDiagnostics, agentPath).configure();
     return LoggerFactory.getLogger("com.microsoft.applicationinsights.agent");
   }
+
+  @Nullable
+  private static String getCodelessSdkNamePrefix() {
+    if (!DiagnosticsHelper.isRpIntegration()) {
+      return null;
+    }
+    StringBuilder sdkNamePrefix = new StringBuilder(4);
+    sdkNamePrefix.append(DiagnosticsHelper.rpIntegrationChar());
+    if (SystemInformation.isWindows()) {
+      sdkNamePrefix.append("w");
+    } else if (SystemInformation.isLinux()) {
+      sdkNamePrefix.append("l");
+    } else {
+      LoggerFactory.getLogger("com.microsoft.applicationinsights.agent")
+          .warn("could not detect os: {}", System.getProperty("os.name"));
+      sdkNamePrefix.append("u");
+    }
+    sdkNamePrefix.append("r_"); // "r" is for "recommended"
+    return sdkNamePrefix.toString();
+  }
 }