launchdarkly / js-core

LaunchDarkly monorepo for JavaScript SDKs
Other
14 stars 18 forks source link

Calling require(@launchdarkly/node-server-sdk).init() triggers a never-ending stream of error messages that contain no useful information #559

Closed angolding closed 2 months ago

angolding commented 2 months ago

Is this a support request? Negative.

Describe the bug Recently I updated a React client-side application to Node 22 and Webpack 5.9x with the latest Webpack-cli and dev-server dependencies. Now, when I start the application via Webpack Dev Serve, the LaunchDarkly init process kicks off a never-ending stream of error messages:

info: [LaunchDarkly] Will retry stream connection in 1000 milliseconds
warn: [LaunchDarkly] Received I/O error ([object Object]) for streaming request - will retry

There is no way to increase the retry delay and no way to tell LaunchDarkly to give up after x number of retries. In addition, it appears that the init process starts spawning multiple retry attempts as the amount of messages logged starts increasing.

Since the log message includes no information about what resource is being connected to using what protocol, and because the err.message parameter is an object that is not deserialized into a string, I have no way of diagnosing the cause of the issue.

FWIW, the init() call is made only with our SDK key.

To reproduce I'm guessing that the underlying error is related to an HTTPS proxy but because this bug is about the content of the error messages and how they contain no information to help me debug in any material fashion, I have no way of knowing.

Anyways,

  1. have an app running on a machine using an HTTPS proxy that has issues its own cert. This may also fail if the streaming server presents a bad HTTPS cert but because there's too much unknown about why my connection is failing, I don't know.
  2. in that app, invoke launchDarkly.init() (launchDarkly in this case is a const assigned to the result of require(@launchdarkly/node-server-sdk))
  3. The streaming processor should fail. behold the never-end wall of errors

Expected behavior

  1. first and foremost: streaming retry-on-error behavior MUST BE configurable. In most cases, I'm not going to need LaunchDarkly running in Webpack Dev Serve so while I am interested in the init() call erroring out, I would also appreciate if it did so for 3-5 times, waiting maybe 15 seconds between retries, and then gave up.
  2. I/O error [Object object] is not a helpful error message. The SDK may need to introspect the message and either stringify an object, stringify across an array, or just display a string
  3. Better logging: when a connection fails, tell me about what the application is trying to connect to using what protocol. There is no reason to hide this from anybody
  4. Make sure not to spawn multiple threads each retrying the same operation in a manner that is permanently increasing.

Logs info: [LaunchDarkly] Will retry stream connection in 1000 milliseconds warn: [LaunchDarkly] Received I/O error ([object Object]) for streaming request - will retry ...

SDK version "@launchdarkly/node-server-sdk": "^9.5.2"

Language version, developer tools Node 20+ (observed in 22.7 and the latest lts/iron (Node 20ish)

OS/platform OS X. Http/Https going through Zproxy

Additional context Add any other context about the problem here.

kinyoklion commented 2 months ago

Hello @angolding,

Thank you for the report. There are a few things to go over before getting to the underlying issue or the log.

There is no way to increase the retry delay and no way to tell LaunchDarkly to give up after x number of retries.

The streamInitialReconnectDelay controls the initial attempt to connect. There is no way to limit the retries. The streaming connection is used to get the flag configuration and updates from LaunchDarkly, so the SDK will continue to retry indefinitely. It does this using a backoff strategy of exponential with a jitter. So a base of 1,2,4,8,16, so forth. Then it applied up to 50% jitter. So the 5th step could be 8-16 seconds of delay. It stops increasing at 30 seconds of base delay. We never stop trying to reconnect as it is a fundamental part of operation.

If you do not want a streaming connection when running in development, then you can use offline mode if you do not need flag updates in this configuration, or you can use polling which has a configurable interval.

Next is that you are talking about a react application, but this report is for the node-server-sdk. So I do want to validate that the SDK is only being used in server aspects of this implementation.

In regards to the log, I would like to double check what version of @launchdarkly/js-sdk-common you have (from checking your lock file). This message was changed at a specific point and shouldn't be reporting an [object Object] anymore.

The only type of protocol the SDK uses it https unless you specifically configure it to connect to HTTP endpoints, and unfortunately the revised error message doesn't provide better information. This situation arises when the underlying connection closes without any reported reason, just that there is an error and no message associated with it.

It should be Received I/O error (unknown error). We do not stringify unknown JSON objects as the error objects often contain circular references and may contain things like credentials that are not desirable in logs.

The SDK also supports proxy configuration.

  /**
   * Allows you to specify configuration for an optional HTTP proxy.
   */
  proxyOptions?: LDProxyOptions;
export interface LDProxyOptions {
  /**
   * Allows you to specify a host for an optional HTTP proxy.
   */
  host?: string;

  /**
   * Allows you to specify a port for an optional HTTP proxy.
   *
   * Both the host and port must be specified to enable proxy support.
   */
  port?: number;

  /**
   * When using an HTTP proxy, specifies whether it is accessed via `http` or `https`.
   */
  scheme?: string;

  /**
   * Allows you to specify basic authentication parameters for an optional HTTP proxy.
   * Usually of the form `username:password`.
   */
  auth?: string;
}

As well as TLS options for things like self-signed certificates.

  /**
   * Additional parameters to pass to the Node HTTPS API for secure requests.  These can include any
   * of the TLS-related parameters supported by `https.request()`, such as `ca`, `cert`, and `key`.
   *
   * For more information, see the Node documentation for `https.request()` and `tls.connect()`.
   */
  tlsParams?: LDTLSOptions;
export interface LDTLSOptions {
  ca?: string | string[] | Buffer | Buffer[];
  cert?: string | string[] | Buffer | Buffer[];
  checkServerIdentity?: (servername: string, cert: any) => Error | undefined;
  ciphers?: string;
  pfx?: string | string[] | Buffer | Buffer[] | object[];
  key?: string | string[] | Buffer | Buffer[] | object[];
  passphrase?: string;
  rejectUnauthorized?: boolean;
  secureProtocol?: string;
  servername?: string;
}

Thank you, Ryan

angolding commented 2 months ago

@kinyoklion Thanks for the info!

To confirm: the issue is with the node SDK running in a node application (the webpack dev server).

Looks like either I had an old dependency or there was an extremely recent and timely change, the message is now:

warn: [LaunchDarkly] Received I/O error (Read timeout, received no data in 300000ms, assuming connection is dead) for streaming request - will retry
info: [LaunchDarkly] Will retry stream connection in 1620 milliseconds

and exponential back-off with jitter on the retry delay is happening.

I'll look into adding proxy configuration to the init() call.

I would say that the error message does not provide enough information (again, what am I talking to? yeah, sometimes the only information is "read timed out" but I still need to know what it is I am reading from). Having more information in errors helps users like me who are stuck behind proxies figure out what additional configuration is needed.

below are the package-lock.json versions:

    "node_modules/@launchdarkly/js-sdk-common": {
      "version": "2.7.0",
      "resolved": "https://geico.pkgs.visualstudio.com/6fa5bc55-1a03-46c9-9c45-58fc01ba4cc5/_packaging/IT.Claims/npm/registry/@launchdarkly/js-sdk-common/-/js-sdk-common-2.7.0.tgz",
      "integrity": "sha1-lH5CQUnhQbim6WysQaiNuXEpuMA=",
      "dev": true,
      "license": "Apache-2.0"
    },
    "node_modules/@launchdarkly/js-server-sdk-common": {
      "version": "2.5.0",
      "resolved": "https://geico.pkgs.visualstudio.com/6fa5bc55-1a03-46c9-9c45-58fc01ba4cc5/_packaging/IT.Claims/npm/registry/@launchdarkly/js-server-sdk-common/-/js-server-sdk-common-2.5.0.tgz",
      "integrity": "sha1-aeyk3t2HYLDdNt9lV8pnXHgY0Q0=",
      "dev": true,
      "license": "Apache-2.0",
      "dependencies": {
        "@launchdarkly/js-sdk-common": "2.7.0",
        "semver": "7.5.4"
      }
    },
    "node_modules/@launchdarkly/js-server-sdk-common/node_modules/lru-cache": {
      "version": "6.0.0",
      "resolved": "https://geico.pkgs.visualstudio.com/6fa5bc55-1a03-46c9-9c45-58fc01ba4cc5/_packaging/IT.Claims/npm/registry/lru-cache/-/lru-cache-6.0.0.tgz",
      "integrity": "sha1-bW/mVw69lqr5D8rR2vo7JWbbOpQ=",
      "dev": true,
      "license": "ISC",
      "dependencies": {
        "yallist": "^4.0.0"
      },
      "engines": {
        "node": ">=10"
      }
    },
    "node_modules/@launchdarkly/js-server-sdk-common/node_modules/semver": {
      "version": "7.5.4",
      "resolved": "https://geico.pkgs.visualstudio.com/6fa5bc55-1a03-46c9-9c45-58fc01ba4cc5/_packaging/IT.Claims/npm/registry/semver/-/semver-7.5.4.tgz",
      "integrity": "sha1-SDmG7E7TjhxsSMNIlKkYLb/2im4=",
      "dev": true,
      "license": "ISC",
      "dependencies": {
        "lru-cache": "^6.0.0"
      },
      "bin": {
        "semver": "bin/semver.js"
      },
      "engines": {
        "node": ">=10"
      }
    },
    "node_modules/@launchdarkly/js-server-sdk-common/node_modules/yallist": {
      "version": "4.0.0",
      "resolved": "https://geico.pkgs.visualstudio.com/6fa5bc55-1a03-46c9-9c45-58fc01ba4cc5/_packaging/IT.Claims/npm/registry/yallist/-/yallist-4.0.0.tgz",
      "integrity": "sha1-m7knkNnA7/7GO+c1GeEaNQGaOnI=",
      "dev": true,
      "license": "ISC"
    },
    "node_modules/@launchdarkly/node-server-sdk": {
      "version": "9.5.2",
      "resolved": "https://geico.pkgs.visualstudio.com/6fa5bc55-1a03-46c9-9c45-58fc01ba4cc5/_packaging/IT.Claims/npm/registry/@launchdarkly/node-server-sdk/-/node-server-sdk-9.5.2.tgz",
      "integrity": "sha1-ucHeawB1Wh24Zx9KSF6BDB5saZw=",
      "dev": true,
      "license": "Apache-2.0",
      "dependencies": {
        "@launchdarkly/js-server-sdk-common": "2.5.0",
        "https-proxy-agent": "^5.0.1",
        "launchdarkly-eventsource": "2.0.3"
      }
    },
angolding commented 2 months ago

@kinyoklion proxy options solved the source issue, so thanks for that! I would still advocate for more log information as previously said.

kinyoklion commented 2 months ago

@angolding Glad to hear that worked for you. I filed an internal ticket to consider improvements to that log message.

As you were able to get things working I will be closing this ticket.

Thank you! Ryan

Filed internally as 254907