Repository: microsoft/ApplicationInsights-node.js
Pull request #581 (2020-01-14 23:10:50)

feat: add status.json logger
- Adds [`status.json`](https://microsoft-my.sharepoint.com/:w:/p/arlittle/EXEv8k1MTDJAs6TnnBTHMLIBRbqR50EqphCIx5SN_WQ_6g?e=Vsk3Ye) logger for attach time diagnostics


Patch:
diff --git a/Bootstrap/Default.ts b/Bootstrap/Default.ts
index 6a2e81f..76a1d79 100644
--- a/Bootstrap/Default.ts
+++ b/Bootstrap/Default.ts
@@ -1,4 +1,5 @@
 import * as types from "../applicationinsights";
+import * as StatusLogger from "./StatusLogger";
 
 // Private configuration vars
 let _appInsights: typeof types | null;
@@ -6,8 +7,15 @@ let _logger: AgentLogger = console;
 let _prefix = "ad_"; // App Services, Default
 
 // Env var local constants
+const ENV_extensionVersion = "APPLICATIONINSIGHTS_EXTENSION_VERSION";
 const _setupString = process.env.APPLICATIONINSIGHTS_CONNECTION_STRING || process.env.APPINSIGHTS_INSTRUMENTATION_KEY;
-const _extensionEnabled = process.env.APPLICATIONINSIGHTS_EXTENSION_VERSION && process.env.APPLICATIONINSIGHTS_EXTENSION_VERSION !== "disabled";
+const _extensionEnabled = process.env[ENV_extensionVersion] && process.env[ENV_extensionVersion] !== "disabled";
+
+// Other local constants
+const defaultStatus: StatusLogger.StatusContract = {
+    ...StatusLogger.DEFAULT_STATUS,
+    Ikey: _setupString,
+};
 
 export interface AgentLogger {
     log(message?: any, ...optional: any[]): void;
@@ -51,18 +59,40 @@ export function setUsagePrefix(prefix: string) {
 }
 
 /**
- * Try to setup and start this app insights instance, if attach is enabled.
+ * Try to setup and start this app insights instance if attach is enabled.
  * @param setupString connection string or instrumentation key
  */
 export function setupAndStart(setupString = _setupString): typeof types | null {
-    if (!_extensionEnabled && sdkAlreadyExists() === false) {
+    StatusLogger.addCloseHandler();
+
+    if (!_extensionEnabled) {
+        StatusLogger.writeFile({
+            ...defaultStatus,
+            AgentInitializedSuccessfully: false,
+            Reason: `Extension is not enabled. env.${ENV_extensionVersion}=${process.env[ENV_extensionVersion]}`
+        });
+        return null;
+    }
+
+    // If app already contains SDK, skip agent attach
+    if (sdkAlreadyExists()) {
+        StatusLogger.writeFile({
+            ...defaultStatus,
+            AgentInitializedSuccessfully: false,
+            SDKPresent: true,
+            Reason: "SDK already exists. Instrumenting using Application Insights SDK"
+        })
         return null;
     }
+
     if (!setupString) {
-        _logger.error(
-            "Application Insights wanted to be started, but no Connection String or Instrumentation Key was provided",
-            setupString
-        );
+        const message = "Application Insights wanted to be started, but no Connection String or Instrumentation Key was provided";
+        _logger.error(message, setupString);
+        StatusLogger.writeFile({
+            ...defaultStatus,
+            AgentInitializedSuccessfully: false,
+            Reason: message,
+        });
         return null;
     }
 
@@ -77,12 +107,25 @@ export function setupAndStart(setupString = _setupString): typeof types | null {
             }
             return true;
         }
+
+        // Instrument the SDK
         _appInsights.setup(setupString).setSendLiveMetrics(true);
         _appInsights.defaultClient.addTelemetryProcessor(prefixInternalSdkVersion);
         _appInsights.start();
+
+        // Agent successfully instrumented the SDK
         _logger.log("Application Insights was started with setupString", setupString, _extensionEnabled);
+        StatusLogger.writeFile({
+            ...defaultStatus,
+            AgentInitializedSuccessfully: true
+        });
     } catch (e) {
         _logger.error("Error setting up Application Insights", e);
+        StatusLogger.writeFile({
+            ...defaultStatus,
+            AgentInitializedSuccessfully: false,
+            Reason: `Error setting up Application Insights: ${e && e.message}`
+        })
     }
     return _appInsights;
 }
diff --git a/Bootstrap/StatusLogger.ts b/Bootstrap/StatusLogger.ts
new file mode 100644
index 0000000..71f6211
--- /dev/null
+++ b/Bootstrap/StatusLogger.ts
@@ -0,0 +1,102 @@
+import * as os from "os";
+import * as path from "path";
+import * as fs from "fs";
+
+export interface StatusContract {
+    AgentInitializedSuccessfully: boolean;
+    Reason?: string;
+    SDKPresent: boolean;
+    AppType: string;
+    MachineName: string;
+    PID: string;
+    SdkVersion: string;
+    Ikey: string;
+}
+
+const _APP_TYPE = "node.js";
+const _HOME_DIR = os.homedir ? os.homedir() :( process.env[(process.platform == 'win32') ? 'USERPROFILE' : 'HOME']);
+const _FILE_PATH = `${_HOME_DIR}/LogFiles/ApplicationInsights/status/`;
+const _FILE_NAME = `status_${os.hostname()}_${process.pid}.json`;
+export const FULL_PATH = _FILE_PATH + _FILE_NAME;
+
+function readPackageVersion() {
+    let packageJsonPath = path.resolve(__dirname, "../package.json");
+    try {
+        let packageJson = JSON.parse(fs.readFileSync(packageJsonPath, "utf8"));
+        if (packageJson && typeof packageJson.version === "string") {
+            return packageJson.version;
+        }
+    } catch (e) {}
+    return "unknown";
+}
+
+/**
+ * Zero dependencies: recursive mkdir
+ */
+function mkDirByPathSync(targetDir: string, { isRelativeToScript = false } = {}) {
+    const sep = path.sep;
+    const initDir = path.isAbsolute(targetDir) ? sep : '';
+    const baseDir = isRelativeToScript ? __dirname : '.';
+
+    return targetDir.split(sep).reduce((parentDir, childDir) => {
+      const curDir = path.resolve(baseDir, parentDir, childDir);
+      try {
+        fs.mkdirSync(curDir);
+      } catch (err) {
+        if (err.code === 'EEXIST') { // curDir already exists!
+          return curDir;
+        }
+
+        // To avoid `EISDIR` error on Mac and `EACCES`-->`ENOENT` and `EPERM` on Windows.
+        if (err.code === 'ENOENT') { // Throw the original parentDir error on curDir `ENOENT` failure.
+          throw new Error(`EACCES: permission denied, mkdir '${parentDir}'`);
+        }
+
+        const caughtErr = ['EACCES', 'EPERM', 'EISDIR'].indexOf(err.code) > -1;
+        if (!caughtErr || caughtErr && curDir === path.resolve(targetDir)) {
+          throw err; // Throw if it's just the last created dir.
+        }
+      }
+
+      return curDir;
+    }, initDir);
+}
+
+export function isNodeVersionCompatible() {
+  const majVer = process.versions.node.split(".")[0];
+  return parseInt(majVer) >= 1;
+}
+
+export const DEFAULT_STATUS: StatusContract = {
+    AgentInitializedSuccessfully: false,
+    SDKPresent: false,
+    Ikey: null,
+    AppType: _APP_TYPE,
+    SdkVersion: readPackageVersion(),
+    MachineName: os.hostname(),
+    PID: String(process.pid)
+}
+
+export function makeStatusDirs(path = _FILE_PATH) {
+    return mkDirByPathSync(path);
+}
+
+export function writeFile(data: StatusContract, cb?: Function) {
+    fs.open(FULL_PATH, "w", (err, fid) => {
+        if (err) return;
+        console.log(FULL_PATH);
+        fs.writeFile(FULL_PATH, JSON.stringify(data, null, 2), { encoding: "utf8" }, (err) => {
+            if (err) {
+                console.error("Error writing Application Insights status file", err);
+            } else if (cb && typeof cb === "function") {
+                cb(err);
+            }
+        });
+    });
+}
+
+export function addCloseHandler() {
+    process.on("exit", () => { try {
+        fs.unlinkSync(FULL_PATH);
+    } catch (err) { }});
+}
diff --git a/Library/Context.ts b/Library/Context.ts
index 24de5da..e5b93fb 100644
--- a/Library/Context.ts
+++ b/Library/Context.ts
@@ -26,7 +26,7 @@ class Context {
     private _loadApplicationContext(packageJsonPath?: string) {
         // note: this should return the host package.json
         packageJsonPath = packageJsonPath || path.resolve(__dirname, "../../../../package.json");
-        
+
         if (!Context.appVersion[packageJsonPath]) {
             Context.appVersion[packageJsonPath] = "unknown";
             try {
@@ -56,7 +56,7 @@ class Context {
     private _loadInternalContext() {
         // note: this should return the sdk package.json
         let packageJsonPath = path.resolve(__dirname, "../../package.json");
-        
+
         if (!Context.sdkVersion) {
             Context.sdkVersion = "unknown";
             try {


Test patch:
diff --git a/Tests/AutoCollection/Exceptions.tests.ts b/Tests/AutoCollection/Exceptions.tests.ts
index b264f01..c464451 100644
--- a/Tests/AutoCollection/Exceptions.tests.ts
+++ b/Tests/AutoCollection/Exceptions.tests.ts
@@ -19,6 +19,8 @@ describe("AutoCollection/Exceptions", () => {
             assert.equal(processOnSpy.callCount, 2, "After enabling exception autocollection, there should be 2 calls to processOnSpy");
             assert.equal(processOnSpy.getCall(0).args[0], AutoCollectionExceptions.UNCAUGHT_EXCEPTION_HANDLER_NAME);
             assert.equal(processOnSpy.getCall(1).args[0], AutoCollectionExceptions.UNHANDLED_REJECTION_HANDLER_NAME);
+            processOnSpy.restore();
+            processRemoveListenerSpy.restore();
         });
     });
 });
diff --git a/Tests/Bootstrap/StatusLogger.spec.ts b/Tests/Bootstrap/StatusLogger.spec.ts
new file mode 100644
index 0000000..a271ab4
--- /dev/null
+++ b/Tests/Bootstrap/StatusLogger.spec.ts
@@ -0,0 +1,34 @@
+import * as fs from "fs";
+import assert = require("assert");
+import sinon = require("sinon");
+import * as StatusLogger from "../../Bootstrap/StatusLogger";
+
+describe("#writeFile()", () => {
+    it("should write a status file to disk", (done) => {
+        if (!StatusLogger.isNodeVersionCompatible()) {
+            done();
+        } else {
+            StatusLogger.makeStatusDirs();
+            StatusLogger.writeFile(StatusLogger.DEFAULT_STATUS, () => {
+                const buffer = JSON.parse(fs.readFileSync(StatusLogger.FULL_PATH, "utf8"));
+                assert.deepEqual(buffer, StatusLogger.DEFAULT_STATUS);
+                done();
+            });
+        }
+    });
+});
+
+describe("#addCloseHandler()", () => {
+    it("should add a process exit handler", () => {
+        if (StatusLogger.isNodeVersionCompatible()) {
+            const processSpy = sinon.spy(process, "on");
+            assert.ok(processSpy.notCalled);
+
+            StatusLogger.addCloseHandler();
+            assert.equal(processSpy.callCount, 1);
+            assert.equal(processSpy.args[0][0], "exit");
+
+            processSpy.restore();
+        }
+    })
+});