Add 15 Second Delay to Long Interval Statsbeat & Fix Tests (#1440)

* Add 15 second delay to long interval statsbeat.

* Update timer.

* Attempt to make backward compatible.

* Update and fix tests.

* Remove node 12

* Update package.json

* Update backcompat.yml

* Remove unneeded removals.

* Update AzureFunctionsHook.ts

* Update AzureFunctionsHook.ts

* Update integration.yml

Author: JacksonWeber

.github/workflows/backcompat.yml

@@ -13,7 +13,7 @@ jobs:
 
     strategy:
       matrix:
-        node-version: [12.x]
+        node-version: [14.x]
 
     steps:
     - uses: actions/checkout@v2

.github/workflows/integration.yml

@@ -13,7 +13,7 @@ jobs:
 
     strategy:
       matrix:
-        node-version: [12.x]
+        node-version: [16.x]
 
     steps:
     - uses: actions/checkout@v2

.github/workflows/node.js.yml

@@ -12,7 +12,7 @@ jobs:
     strategy:
       matrix:
         os: [ubuntu-latest]
-        node-version: [8, 10, 12, 14, 16, 17, 18]
+        node-version: [14, 16, 17, 18]
 
     steps:
     - uses: actions/checkout@v2

.github/workflows/test.yml

@@ -11,7 +11,7 @@ jobs:
     strategy:
       matrix:
         os: [ubuntu-latest]
-        node-version: [12, 14, 16, 18]
+        node-version: [14, 16, 18]
 
     steps:
     - uses: actions/checkout@v2

AutoCollection/Statsbeat.ts

@@ -18,6 +18,7 @@ class Statsbeat {
     public static EU_CONNECTION_STRING = "InstrumentationKey=7dc56bab-3c0c-4e9f-9ebb-d1acadee8d0f;IngestionEndpoint=https://westeurope-5.in.applicationinsights.azure.com";
     public static STATS_COLLECTION_SHORT_INTERVAL: number = 900000; // 15 minutes
     public static STATS_COLLECTION_LONG_INTERVAL: number = 86400000; // 1 day
+    public static STATS_COLLECTION_INITIAL_DELAY: number = 15000; // 15 seconds
 
     private static TAG = "Statsbeat";
 
@@ -26,6 +27,7 @@ class Statsbeat {
     private _context: Context;
     private _handle: NodeJS.Timer | null;
     private _longHandle: NodeJS.Timer | null;
+    private _longHandleTimeout: NodeJS.Timer | null;
     private _isEnabled: boolean;
     private _isInitialized: boolean;
     private _config: Config;
@@ -51,6 +53,7 @@ class Statsbeat {
         this._networkStatsbeatCollection = [];
         this._config = config;
         this._context = context || new Context();
+        this._longHandleTimeout = null;
         let statsbeatConnectionString = this._getConnectionString(config);
         this._statsbeatConfig = new Config(statsbeatConnectionString);
         this._statsbeatConfig.samplingPercentage = 100; // Do not sample
@@ -71,8 +74,13 @@ class Statsbeat {
                 this._handle.unref(); // Allow the app to terminate even while this loop is going on
             }
             if (!this._longHandle) {
-                // On first enablement
-                this.trackLongIntervalStatsbeats();
+                // Add 15 second delay before first long interval statsbeat
+                this._longHandleTimeout = setTimeout(() => {
+                    if (this.isEnabled()) {
+                        this.trackLongIntervalStatsbeats();
+                    }
+                }, Statsbeat.STATS_COLLECTION_INITIAL_DELAY);
+                this._longHandleTimeout.unref(); // Allow the app to terminate even while this loop is going on
                 this._longHandle = setInterval(() => {
                     this.trackLongIntervalStatsbeats();
                 }, Statsbeat.STATS_COLLECTION_LONG_INTERVAL);
@@ -87,6 +95,10 @@ class Statsbeat {
                 clearInterval(this._longHandle);
                 this._longHandle = null;
             }
+            if (this._longHandleTimeout) {
+                clearTimeout(this._longHandleTimeout);
+                this._longHandleTimeout = null;
+            }
         }
     }
 

Library/Sender.ts

@@ -1,4 +1,4 @@
-import fs = require("fs");
+import fs = require("fs");
 import http = require("http");
 import os = require("os");
 import path = require("path");

Tests/AutoCollection/NativePerformance.tests.ts

@@ -24,28 +24,27 @@ describe("AutoCollection/NativePerformance", () => {
 
     describe("#init and #dispose()", () => {
         it("init should enable and dispose should stop autocollection interval", () => {
+            var client = new TelemetryClient("1aa11111-bbbb-1ccc-8ddd-eeeeffff3333");
             var setIntervalSpy = sandbox.spy(global, "setInterval");
             var clearIntervalSpy = sandbox.spy(global, "clearInterval");
-            const statsAddSpy = sandbox.spy(AutoCollectNativePerformance.INSTANCE["_statsbeat"], "addFeature");
-            const statsRemoveSpy = sandbox.spy(AutoCollectNativePerformance.INSTANCE["_statsbeat"], "removeFeature");
-
-            AppInsights.setup("1aa11111-bbbb-1ccc-8ddd-eeeeffff3333")
-                .setAutoCollectHeartbeat(false)
-                .setAutoCollectPerformance(false, true)
-                .setAutoCollectPreAggregatedMetrics(false)
-                .start();
+            var native = new AutoCollectNativePerformance(client);
+
+            // Enable auto collection
+            native.enable(true);
+
+            if (AutoCollectNativePerformance["_metricsAvailable"]) {
+                assert.equal(setIntervalSpy.callCount, 1, "setInterval should be called when enabling");
+            } else {
+                assert.equal(setIntervalSpy.callCount, 0, "setInterval should not be called if native metrics package is not installed");
+            }
+
+            // Dispose should stop the interval
+            native.dispose();
+
             if (AutoCollectNativePerformance["_metricsAvailable"]) {
-                assert.ok(statsAddSpy.calledOnce);
-                assert.strictEqual(AutoCollectNativePerformance.INSTANCE["_statsbeat"]["_feature"], Constants.StatsbeatFeature.NATIVE_METRICS + Constants.StatsbeatFeature.DISK_RETRY);
-                assert.equal(setIntervalSpy.callCount, 3, "setInteval should be called three times as part of NativePerformance initialization as well as Statsbeat");
-                AppInsights.dispose();
-                assert.ok(statsRemoveSpy.calledOnce);
-                assert.strictEqual(AutoCollectNativePerformance.INSTANCE["_statsbeat"]["_feature"], Constants.StatsbeatFeature.DISK_RETRY);
-                assert.equal(clearIntervalSpy.callCount, 1, "clearInterval should be called once as part of NativePerformance shutdown");
+                assert.equal(clearIntervalSpy.callCount, 1, "clearInterval should be called when disposing");
             } else {
-                assert.equal(setIntervalSpy.callCount, 2, "setInterval should not be called if NativePerformance package is not available, Statsbeat will be called");
-                AppInsights.dispose();
-                assert.equal(clearIntervalSpy.callCount, 0, "clearInterval should not be called if NativePerformance package is not available");
+                assert.equal(clearIntervalSpy.callCount, 0, "clearInterval should not be called if native metrics package is not installed");
             }
         });
 

Tests/AutoCollection/Statsbeat.tests.ts

@@ -356,4 +356,102 @@ describe("AutoCollection/Statsbeat", () => {
             }).catch((error) => { done(error); });
         });
     });
+
+    describe("#enable() with long interval delay", () => {
+        let clock: sinon.SinonFakeTimers;
+
+        beforeEach(() => {
+            clock = sinon.useFakeTimers();
+        });
+
+        afterEach(() => {
+            clock.restore();
+        });
+
+        it("should delay first long interval statsbeat by 15 seconds", (done) => {
+            const trackLongIntervalSpy = sandbox.spy(statsBeat, "trackLongIntervalStatsbeats");
+            
+            // Enable statsbeat
+            statsBeat.enable(true);
+            
+            // Immediately after enabling, trackLongIntervalStatsbeats should not have been called
+            assert.equal(trackLongIntervalSpy.callCount, 0, "trackLongIntervalStatsbeats should not be called immediately");
+            
+            // Fast-forward 10 seconds - still should not be called
+            clock.tick(10000);
+            assert.equal(trackLongIntervalSpy.callCount, 0, "trackLongIntervalStatsbeats should not be called after 10 seconds");
+            
+            // Fast-forward to 15 seconds - now it should be called
+            clock.tick(5000);
+            assert.equal(trackLongIntervalSpy.callCount, 1, "trackLongIntervalStatsbeats should be called after 15 seconds");
+            
+            done();
+        });
+
+        it("should call trackLongIntervalStatsbeats on regular interval after initial delay", (done) => {
+            const trackLongIntervalSpy = sandbox.spy(statsBeat, "trackLongIntervalStatsbeats");
+            
+            // Enable statsbeat
+            statsBeat.enable(true);
+            
+            // Fast-forward to the first call (15 seconds)
+            clock.tick(15000);
+            assert.equal(trackLongIntervalSpy.callCount, 1, "First call should happen after 15 seconds");
+            
+            // Fast-forward by the long interval (24 hours)
+            clock.tick(Statsbeat.STATS_COLLECTION_LONG_INTERVAL);
+            assert.equal(trackLongIntervalSpy.callCount, 2, "Second call should happen after the interval");
+            
+            // Fast-forward by another long interval
+            clock.tick(Statsbeat.STATS_COLLECTION_LONG_INTERVAL);
+            assert.equal(trackLongIntervalSpy.callCount, 3, "Third call should happen after another interval");
+            
+            done();
+        });
+
+        it("should not delay if enable is called multiple times", (done) => {
+            const trackLongIntervalSpy = sandbox.spy(statsBeat, "trackLongIntervalStatsbeats");
+            
+            // Enable statsbeat first time
+            statsBeat.enable(true);
+            
+            // Fast-forward 5 seconds
+            clock.tick(5000);
+            assert.equal(trackLongIntervalSpy.callCount, 0, "Should not be called yet");
+            
+            // Disable and re-enable (simulating multiple enable calls)
+            statsBeat.enable(false);
+            statsBeat.enable(true);
+            
+            // The second enable should start a new 15-second timer
+            clock.tick(10000); // Total 15 seconds from first enable, but only 10 from second
+            assert.equal(trackLongIntervalSpy.callCount, 0, "Should not be called yet after re-enable");
+            
+            // Fast-forward another 5 seconds (15 seconds from second enable)
+            clock.tick(5000);
+            assert.equal(trackLongIntervalSpy.callCount, 1, "Should be called 15 seconds after re-enable");
+            
+            done();
+        });
+
+        it("should handle disable before initial delay completes", (done) => {
+            const trackLongIntervalSpy = sandbox.spy(statsBeat, "trackLongIntervalStatsbeats");
+            
+            // Enable statsbeat
+            statsBeat.enable(true);
+            
+            // Fast-forward 10 seconds (before the 15-second delay completes)
+            clock.tick(10000);
+            assert.equal(trackLongIntervalSpy.callCount, 0, "Should not be called yet");
+            
+            // Disable before the delay completes
+            statsBeat.enable(false);
+            
+            // Fast-forward past where the call would have happened
+            clock.tick(10000); // Total 20 seconds
+            assert.equal(trackLongIntervalSpy.callCount, 0, "Should not be called after disable");
+            
+            done();
+        });
+    });
 });