documentdb - npm Package Compare versions

Comparing version 1.15.1 to 1.15.2

changelog.md

@@ -0,1 +1,9 @@
+## Changes in 1.15.2
+- Adds additional logging and hardening. This includes additional error/warn/info logs which have information about the https.agent state + all errors are now logged
+- Adds a separate watchdog timeout on https requests to handle cases where https.request/socket timeouts themselves get bogged down. This time produces a scary looking error as you'll only see it when running under too much load for a given client/app.
+- Adds `isTimedout` and `duration` to error messages that come from request pipeline. These indicate whether a timeout occurred for the error and what the duration of the request is as measure from the creation of the request callback itself (not based on socket time/etc.)
+
+## Changes in 1.15.1
+- Adds additional logging and hardening
+
 ## Changes in 1.15.0
@@ -2,0 +10,0 @@ - Adds logging support

lib/constants.js

@@ -193,3 +193,3 @@ /*
     SDKName: "documentdb-nodejs-sdk",
-    SDKVersion: "1.15.1",
+    SDKVersion: "1.15.2",
 
@@ -196,0 +196,0 @@ DefaultPrecisions: {

lib/documents.js

@@ -301,2 +301,10 @@ /*
 
+            // Not intended to be modified by users
+            Object.defineProperty(this, "_requestWatchDogWaitTime", {
+                value: 2000,
+                writable: true,
+                configurable: true,
+                enumerable: false // this is the default value, so it could be excluded during JSON.stringify
+            });
+
             this.ConnectionMode = AzureDocuments.ConnectionMode.Gateway;
@@ -303,0 +311,0 @@ this.MediaReadMode = AzureDocuments.MediaReadMode.Buffered;

lib/request.js

@@ -57,13 +57,50 @@ /*
 function createRequestObject(connectionPolicy, requestOptions, callback) {
+    var requestStart = new Date();
+
+    var timeoutCalled = false;
     function onTimeout() {
-        log.error("[onTimeout] Timeout occurred")
+        timeoutCalled = true;
+        var duration = (new Date()) - requestStart;
+        log.error("[onTimeout] Timeout occurred. Aborting request after " + duration + " ms. Agent - freesockets: " + Object.keys(requestOptions.agent.freeSockets).length + ", sockets: " + Object.keys(requestOptions.agent.sockets).length + ", requests: " + Object.keys(requestOptions.agent.requests).length);
         httpsRequest.abort();
     }
 
+    var watchDog = setTimeout(function() {
+        log.error("[watchdog] Watchdog called. Killing request.");
+        onTimeout();
+        const err = new Error("CRITICAL: Request manually aborted past timeout via watchdog. This error is only returned if socket.timeout is not called in time. You likely need to reduce the load on your client or increase the number of available sockets.");
+        err.code = 503;
+        err.isTimedout = true;
+        onComplete(err, undefined, undefined);
+    }, connectionPolicy.RequestTimeout + connectionPolicy._requestWatchDogWaitTime);
+
     var isMedia = (requestOptions.path.indexOf("//media") === 0);
 
+    var isComplete = false;
+    var onComplete = function(err, response, headers) {
+        clearTimeout(watchDog);
+
+        if(err) {
+            err.isTimedout = timeoutCalled;
+            err.duration = (new Date()) - requestStart;
+        }
+
+        if(isComplete) {
+            if(err) {
+                log.error("[onComplete] Received non-sucessful response after completion with error: %o", err);
+            } else {
+                log.warn("[onComplete] Received sucessful respones after completion");
+            }
+            return;
+        }
+
+        isComplete = true;
+        
+        callback(err, response, headers);
+    }
+
     var httpsRequest = https.request(requestOptions, function (response) {
         // In case of media response, return the stream to the user and the user will need to handle reading the stream.
         if (isMedia && connectionPolicy.MediaReadMode === Documents.MediaReadMode.Streamed) {
-            return callback(undefined, response, response.headers);
+            return onComplete(undefined, response, response.headers);
         }
@@ -81,5 +118,6 @@
         });
+        
         response.on("end", function () {
             if (response.statusCode >= 400) {
-                return callback(getErrorBody(response, data), undefined, response.headers);
+                return onComplete(getErrorBody(response, data), undefined, response.headers);
             }
@@ -95,6 +133,6 @@
             } catch (exception) {
-                return callback(exception);
+                return onComplete(exception);
             }
 
-            callback(undefined, result, response.headers);
+            onComplete(undefined, result, response.headers);
         });
@@ -117,3 +155,3 @@ });
 
-    httpsRequest.once("error", callback);
+    httpsRequest.once("error", onComplete);
     return httpsRequest;
@@ -120,0 +158,0 @@ }

lib/retryUtility.js

@@ -72,5 +72,8 @@ /*
         var that = this;
+        log.info("[%s] [%s] [%s]", requestOptions.method, requestOptions.host, requestOptions.path);
         log.debug("[apply] Request Options: %o", requestOptions);
         var httpsRequest = createRequestObjectFunc(connectionPolicy, requestOptions, function (err, response, headers) {
             if (err) {
+                // Non-success status codes/errors 
+                log.info("Received error: %o", err);
                 var retryPolicy = null;
@@ -97,2 +100,3 @@ headers = headers || {};
                     } else {
+                        log.info("Retrying in %d ms", retryPolicy.retryAfterInMilliseconds);
                         setTimeout(function () {
@@ -99,0 +103,0 @@ if (typeof newUrl !== 'undefined')

package.json

@@ -14,3 +14,3 @@ {
   ],
-  "version": "1.15.1",
+  "version": "1.15.2",
   "author": "Microsoft Corporation",
@@ -17,0 +17,0 @@ "main": "./index.js",

test/incrementalFeedTests.js

@@ -240,2 +240,3 @@ /*
                         delete result._lsn;
+                        delete result._metadata;
                         assert.deepEqual(result, document, "actual value doesn't match with expected value.");
@@ -242,0 +243,0 @@

New alerts

Environment variable access

Supply chain risk

Package accesses environment variables, which may be a sign of credential stuffing or data theft.

Found 1 instance in 1 package

Fixed alerts

New author

Supply chain risk

A new npm collaborator published a version of the package for the first time. New collaborators are usually benign additions to a project, but do indicate a change to the security surface area of a package.

Found 1 instance in 1 package

Improved metrics

Total package byte prevSize

1606864

increased by0.33%

Lines of code

30793

increased by0.25%

Number of medium supply chain risk alerts

6

decreased by-14.29%

Worsened metrics

Number of low supply chain risk alerts

7

increased by16.67%

No dependency changes