SNOW-926008 supportability/observability enhancement for generic and …

…proxy use-cases (#699) * SNOW-926008 supportability/observability enhancement for generic and proxy use-cases - generic observability: instead of swallowing the underlying error upon connectivity issue and emit a hard-to-debug generic error message, log that underlying error stack on DEBUG loglevel - proxy: detecting if HTTP_PROXY/HTTPS_PROXY environmental variable is set, log them on DEBUG loglevel - proxy: added logging for Connection's proxyPort and proxyUser (if set), had only proxyHost. -- this bit of logging now moved to generic agent - proxy: if both HTTPS_PROXY and proxyHost is set, can lead to not-so-trivial-to-debug situations ; log this on WARN loglevel for more intuitive troubleshooting * * rewrote env proxy detection function with one which can also compare the env PROXY with the agent proxy settings and generate log messages accordingly * moved the proxy (env+agent) detection functionality into agent creation step to try and check it only once, upon agent creation time * adjusted unit tests accordingly * removing accidentally introduced unnecessary empty line
snowflakedb · Nov 16, 2023 · 0f58cec · 0f58cec
1 parent 49c7b13
commit 0f58cec
Show file tree

Hide file tree

Showing 5 changed files with 197 additions and 1 deletion.
diff --git a/lib/agent/https_proxy_ocsp_agent.js b/lib/agent/https_proxy_ocsp_agent.js
@@ -98,7 +98,14 @@ function connect(req, opts, fn)
 {
   var proxy = this.proxy;
   var agent = this;
-  Logger.getInstance().debug("Using proxy=%s for host %s", proxy.host, opts.host);
+
+  // is proxy same as the host it's proxying for? that's a problem
+  // can occur when envvar HTTPS_PROXY is the same as Connection proxyHost
+  if (proxy.host === opts.host) {
+    Logger.getInstance().warn('Looks like the proxy (%s) is the same as the host it is proxying for (%s). '
+        + 'If you have connectivity problems, please check if HTTPS_PROXY and proxyHost:proxyPort '
+        + 'settings are both in effect and if so, try unsetting one of them.', proxy.host, opts.host);
+  };
 
   // create a socket connection to the proxy server
   var socket;

diff --git a/lib/http/node.js b/lib/http/node.js
@@ -53,6 +53,16 @@ function getFromCacheOrCreate(agentClass, options, parsedUrl) {
     const agent = agentClass(agentOptions);
     httpsAgentCache.set(agentId, agent);
     Logger.getInstance().trace(`Create and add to cache new agent ${agentId}`);
+
+    // detect and log PROXY envvar + agent proxy settings
+    const compareAndLogEnvAndAgentProxies = Util.getCompareAndLogEnvAndAgentProxies(agentOptions);
+    Logger.getInstance().debug(`Proxy settings used in requests:${compareAndLogEnvAndAgentProxies.messages}`);
+    // if there's anything to warn on (e.g. both envvar + agent proxy used, and they are different)
+    // log warnings on them
+    if (compareAndLogEnvAndAgentProxies.warnings) {
+      Logger.getInstance().warn(`${compareAndLogEnvAndAgentProxies.warnings}`);
+    }
+
     return agent;
   }
 

diff --git a/lib/services/sf.js b/lib/services/sf.js
@@ -615,6 +615,10 @@ function StateAbstract(options)
           // if we got an error, wrap it into a network error
           if (err)
           {
+            // if we're running in DEBUG loglevel, probably we want to see the full error instead
+            Logger.getInstance().debug('Encountered an error when sending the request. Details: '
+                + JSON.stringify(err, Util.getCircularReplacer()));
+
             err = Errors.createNetworkError(
               ErrorCodes.ERR_SF_NETWORK_COULD_NOT_CONNECT, err);
           }

diff --git a/lib/util.js b/lib/util.js
@@ -637,4 +637,73 @@ exports.getCircularReplacer = function() {
 exports.isCorrectSubdomain = function (value) {
   const subdomainRegex = RegExp(/^\w[\w.-]+\w$/i);
   return subdomainRegex.test(value);
+};
+
+/**
+ * Try to get the PROXY environmental variables
+ * On Windows, envvar name is case-insensitive, but on *nix, it's case-sensitive
+ *
+ * Compare them with the proxy specified on the Connection, if any
+ * Return with the log constructed from the components detection and comparison
+ * If there's something to warn the user about, return that too
+ *
+ * @param the agentOptions object from agent creation
+ * @returns {object}
+ */
+exports.getCompareAndLogEnvAndAgentProxies = function(agentOptions) {
+  const envProxy = {};
+  let logMessages = {'messages': '', 'warnings': ''};
+  envProxy.httpProxy = process.env.HTTP_PROXY || process.env.http_proxy;
+  envProxy.httpsProxy = process.env.HTTPS_PROXY || process.env.https_proxy;
+  envProxy.noProxy = process.env.NO_PROXY || process.env.no_proxy;
+
+  envProxy.logHttpProxy = envProxy.httpProxy ?
+      'HTTP_PROXY: ' + envProxy.httpProxy : 'HTTP_PROXY: <unset>';
+  envProxy.logHttpsProxy = envProxy.httpsProxy ?
+      'HTTPS_PROXY: ' + envProxy.httpsProxy : 'HTTPS_PROXY: <unset>';
+  envProxy.logNoProxy = envProxy.noProxy ?
+      'NO_PROXY: ' + envProxy.noProxy : 'NO_PROXY: <unset>';
+
+  // log PROXY envvars
+  if (envProxy.httpProxy || envProxy.httpsProxy) {
+      logMessages.messages = logMessages.messages + ` // PROXY environment variables: `
+      + `${envProxy.logHttpProxy} ${envProxy.logHttpsProxy} ${envProxy.logNoProxy}.`;
+  }
+
+  // log proxy config on Connection, if any set
+  if (agentOptions.host) {
+      const proxyHostAndPort = agentOptions.host + ':' + agentOptions.port
+      const proxyProtocolHostAndPort = agentOptions.protocol ?
+          ' protocol=' + agentOptions.protocol + ' proxy=' + proxyHostAndPort
+          : ' proxy=' + proxyHostAndPort;
+      const proxyUsername = agentOptions.user ? ' user=' + agentOptions.user : ''
+      logMessages.messages = logMessages.messages + ` // Proxy configured in Connection:${proxyProtocolHostAndPort}${proxyUsername}`;
+
+      // check if both the PROXY envvars and Connection proxy config is set
+      // generate warnings if they are, and are also different
+      if (envProxy.httpProxy &&
+          this.removeScheme(envProxy.httpProxy).toLowerCase() != this.removeScheme(proxyHostAndPort).toLowerCase()) {
+          logMessages.warnings = logMessages.warnings + ` Using both the HTTP_PROXY (${envProxy.httpProxy})`
+          +` and the proxyHost:proxyPort (${proxyHostAndPort}) settings to connect, but with different values.`
+          +` If you experience connectivity issues, try unsetting one of them.`
+      };
+      if (envProxy.httpsProxy &&
+          this.removeScheme(envProxy.httpsProxy).toLowerCase() != this.removeScheme(proxyHostAndPort).toLowerCase()) {
+          logMessages.warnings = logMessages.warnings + ` Using both the HTTPS_PROXY (${envProxy.httpsProxy})`
+          +` and the proxyHost:proxyPort (${proxyHostAndPort}) settings to connect, but with different values.`
+          +` If you experience connectivity issues, try unsetting one of them.`
+      };
+  }
+  logMessages.messages = logMessages.messages ? logMessages.messages : ' none.'
+
+  return logMessages;
+};
+
+/**
+* remove http:// or https:// from the input, e.g. used with proxy URL
+* @param input
+* @returns {string}
+*/
+exports.removeScheme = function (input) {
+  return input.toString().replace(/(^\w+:|^)\/\//, '');
 };
diff --git a/test/unit/util_test.js b/test/unit/util_test.js
@@ -822,4 +822,110 @@ describe('Util', function ()
       assert.deepEqual(replacedB, shouldMatchCircular);
     });
   });
+
+  describe("Util Test - removing http or https from string", () => {
+    const hostAndPortDone = 'my.pro.xy:8080';
+    const ipAndPortDone = '10.20.30.40:8080';
+    const somethingEntirelyDifferentDone = 'something ENTIRELY different';
+
+    [
+      { name: "remove http from url", text: "http://my.pro.xy:8080", shouldMatch: hostAndPortDone },
+      { name: "remove https from url", text: "https://my.pro.xy:8080", shouldMatch: hostAndPortDone },
+      { name: "remove http from ip and port", text: "http://10.20.30.40:8080", shouldMatch: ipAndPortDone },
+      { name: "remove https from ip and port", text: "https://10.20.30.40:8080", shouldMatch: ipAndPortDone },
+      { name: "dont remove http(s) from hostname and port", text: "my.pro.xy:8080", shouldMatch: hostAndPortDone },
+      { name: "dont remove http(s) from ip and port", text: "10.20.30.40:8080", shouldMatch: ipAndPortDone },
+      { name: "dont remove http(s) from simple string", text: somethingEntirelyDifferentDone, shouldMatch: somethingEntirelyDifferentDone}
+    ].forEach(({ name, text, shouldMatch }) => {
+      it(`${name}`, () => {
+        assert.deepEqual(Util.removeScheme(text), shouldMatch);
+      });
+    });
+  });
+
+  describe("Util Test - detecting PROXY envvars and compare with the agent proxy settings", () => {
+    // if for some reason there's already a PROXY envvar, try to preserve it
+    const httpProxyBeforeTest = process.env.HTTP_PROXY ? process.env.HTTP_PROXY : null;
+    const httpsProxyBeforeTest = process.env.HTTPS_PROXY ? process.env.HTTPS_PROXY : null;
+
+    [
+      {
+        name: "detect http_proxy envvar, no agent proxy",
+        isWarn: false,
+        httpproxy: "10.20.30.40:8080",
+        HTTPSPROXY: '',
+        agentOptions: {"keepalive": true},
+        shouldLog: " // PROXY environment variables: HTTP_PROXY: 10.20.30.40:8080 HTTPS_PROXY: <unset> NO_PROXY: <unset>."
+      }, {
+        name: "detect HTTPS_PROXY envvar, no agent proxy",
+        isWarn: false,
+        httpproxy: '',
+        HTTPSPROXY: "http://pro.xy:3128",
+        agentOptions: {"keepalive": true},
+        shouldLog: " // PROXY environment variables: HTTP_PROXY: <unset> HTTPS_PROXY: http://pro.xy:3128 NO_PROXY: <unset>."
+      }, {
+        name: "detect both http_proxy and HTTPS_PROXY envvar, no agent proxy",
+        isWarn: false,
+        httpproxy: "10.20.30.40:8080",
+        HTTPSPROXY: "http://pro.xy:3128",
+        agentOptions: {"keepalive": true},
+        shouldLog: " // PROXY environment variables: HTTP_PROXY: 10.20.30.40:8080 HTTPS_PROXY: http://pro.xy:3128 NO_PROXY: <unset>."
+      }, {
+        name: "detect http_proxy envvar, agent proxy set to an unauthenticated proxy, same as the envvar",
+        isWarn: false,
+        httpproxy: "10.20.30.40:8080",
+        HTTPSPROXY: '',
+        agentOptions: {"keepalive": true, "host": "10.20.30.40", "port": 8080},
+        shouldLog: " // PROXY environment variables: HTTP_PROXY: 10.20.30.40:8080 HTTPS_PROXY: <unset> NO_PROXY: <unset>. // Proxy configured in Connection: proxy=10.20.30.40:8080"
+      }, {
+        name: "detect both http_proxy and HTTPS_PROXY envvar, agent proxy set to an unauthenticated proxy, same as the envvar",
+        isWarn: false,
+        httpproxy: "10.20.30.40:8080",
+        HTTPSPROXY: "http://10.20.30.40:8080",
+        agentOptions: {"keepalive": true, "host": "10.20.30.40", "port": 8080},
+        shouldLog: " // PROXY environment variables: HTTP_PROXY: 10.20.30.40:8080 HTTPS_PROXY: http://10.20.30.40:8080 NO_PROXY: <unset>. // Proxy configured in Connection: proxy=10.20.30.40:8080"
+      }, {
+        name: "detect both http_proxy and HTTPS_PROXY envvar, agent proxy set to an authenticated proxy, same as the envvar",
+        isWarn: false,
+        httpproxy: "10.20.30.40:8080",
+        HTTPSPROXY: "http://10.20.30.40:8080",
+        agentOptions: {"keepalive": true, "host": "10.20.30.40", "port": 8080, "user": "PRX", "password": "proxypass"},
+        shouldLog: " // PROXY environment variables: HTTP_PROXY: 10.20.30.40:8080 HTTPS_PROXY: http://10.20.30.40:8080 NO_PROXY: <unset>. // Proxy configured in Connection: proxy=10.20.30.40:8080 user=PRX"
+      }, {
+        name: "detect both http_proxy and HTTPS_PROXY envvar, agent proxy set to an authenticated proxy, same as the envvar, with the protocol set",
+        isWarn: false,
+        httpproxy: "10.20.30.40:8080",
+        HTTPSPROXY: "http://10.20.30.40:8080",
+        agentOptions: {"keepalive": true, "host": "10.20.30.40", "port": 8080, "user": "PRX", "password": "proxypass", "protocol": "http"},
+        shouldLog: " // PROXY environment variables: HTTP_PROXY: 10.20.30.40:8080 HTTPS_PROXY: http://10.20.30.40:8080 NO_PROXY: <unset>. // Proxy configured in Connection: protocol=http proxy=10.20.30.40:8080 user=PRX"
+      }, {
+      // now some WARN level messages
+        name: "detect HTTPS_PROXY envvar, agent proxy set to an unauthenticated proxy, different from the envvar",
+        isWarn: true,
+        httpproxy: '',
+        HTTPSPROXY: "http://pro.xy:3128",
+        agentOptions: {"keepalive": true, "host": "10.20.30.40", "port": 8080},
+        shouldLog: " Using both the HTTPS_PROXY (http://pro.xy:3128) and the proxyHost:proxyPort (10.20.30.40:8080) settings to connect, but with different values. If you experience connectivity issues, try unsetting one of them."
+      }, {
+        name: "detect both http_proxy and HTTPS_PROXY envvar, different from each other, agent proxy set to an unauthenticated proxy, different from the envvars",
+        isWarn: true,
+        httpproxy: '169.254.169.254:8080',
+        HTTPSPROXY: "http://pro.xy:3128",
+        agentOptions: {"keepalive": true, "host": "10.20.30.40", "port": 8080},
+        shouldLog: " Using both the HTTP_PROXY (169.254.169.254:8080) and the proxyHost:proxyPort (10.20.30.40:8080) settings to connect, but with different values. If you experience connectivity issues, try unsetting one of them. Using both the HTTPS_PROXY (http://pro.xy:3128) and the proxyHost:proxyPort (10.20.30.40:8080) settings to connect, but with different values. If you experience connectivity issues, try unsetting one of them."
+      }
+    ].forEach(({ name, isWarn, httpproxy, HTTPSPROXY, agentOptions, shouldLog }) => {
+      it(`${name}`, () => {
+        process.env.http_proxy = httpproxy;
+        process.env.HTTPS_PROXY = HTTPSPROXY;
+
+        const compareAndLogEnvAndAgentProxies = Util.getCompareAndLogEnvAndAgentProxies(agentOptions);
+        if (!isWarn) {
+          assert.deepEqual(compareAndLogEnvAndAgentProxies.messages, shouldLog, 'expected log message does not match!');
+        } else {
+          assert.deepEqual(compareAndLogEnvAndAgentProxies.warnings, shouldLog, 'expected warning message does not match!');
+        }
+      });
+      });
+    });
 });