launchdarkly / node-server-sdk

LaunchDarkly Server-side SDK for Node
Other
79 stars 65 forks source link

Unexpected token { in JSON at position XYZ #82

Closed magne4000 closed 5 years ago

magne4000 commented 6 years ago

We have a lot of stacktraces like this one on an Electron project:

SyntaxError Unexpected token { in JSON at position 499 
    unknown parse
    node_modules/ldclient-node/streaming.js:25:26 none
    events.js:96:13 emitOne
    events.js:191:7 emit
    node_modules/ldclient-node/eventsource.js:193:17 _emit
    node_modules/ldclient-node/eventsource.js:207:9 parseEventStreamLine
    node_modules/ldclient-node/eventsource.js:170:11 none
    events.js:96:13 emitOne
    events.js:191:7 emit
    _stream_readable.js:178:18 readableAddChunk
    _stream_readable.js:136:10 push
    _http_common.js:123:22 parserOnBody
    _http_client.js:411:20 socketOnData
    events.js:96:13 emitOne
    events.js:191:7 emit
    _stream_readable.js:178:18 readableAddChunk
    _stream_readable.js:136:10 push
    net.js:560:20 onread [as _originalOnread]
    node_modules/async-listener/glue.js:188:31 onread

The position of the unexpected token (here 499) varies from client to client, but the error remains the same. Any clue on what could go wrong, or how I can gather more details ?

eli-darkly commented 6 years ago

Hi. Sorry you're having this problem - it's not one we've seen so far, and I'd like to find out what's going on.

The first thing I'd like to know is what version of the Node SDK you're running; that will help us know exactly which code path corresponds to streaming.js:25. Once I know that, I could show you where to add a log statement to gather more details (if you don't mind creating quite a bit of extra log output).

I can also try to reproduce the problem over here if I know what account and project you're using. You can either email me at eli@launchdarkly.com, or create a support ticket and ask them to pass the information along to me.

Two other things that might help to narrow this down:

  1. Do you know whether this happens just when the client is first being initialized, or repeatedly throughout the lifetime of an existing client (like, when a flag has been changed)?
  2. Are you connecting directly to LaunchDarkly, or using ld-relay?

best, Eli

eli-darkly commented 6 years ago

I forgot to say, it'd also be helpful to know the approximate date/time range when these messages occurred (not every one, just how long ago you first noticed them and whether they are still going on), in case it's correlated with any known service outage in the past.

magne4000 commented 6 years ago

Hi @eli-darkly, thank you for the really quick answer 🙏


The first thing I'd like to know is what version of the Node SDK you're running

3.2.1

Do you know whether this happens just when the client is first being initialized, or repeatedly throughout the lifetime of an existing client (like, when a flag has been changed)?

Not sure, but for some users this error has occured more than 1000 times in the last 2 weeks, so I assume that's happening throughout the lifetime of the clients.

Are you connecting directly to LaunchDarkly, or using ld-relay?

I'm connecting directly to LaunchDarkly

it'd also be helpful to know the approximate date/time range when these messages occurred

The first time the error appeared on our side was on Feb 13th, and it's still ongoing (we have this error reported between 5 and 15 times per minutes from several days now).

I can also try to reproduce the problem over here if I know what account and project you're using. You can either email me at eli@launchdarkly.com, or create a support ticket and ask them to pass the information along to me.

I'm forwarding our project information to you by email.

eli-darkly commented 6 years ago

OK, I'm now running a copy of the Node client, connecting with your credentials (but not doing any flag evaluations, so it won't trigger any analytics events) to see if I can reproduce the JSON error. No luck at present, though - it seems to be working fine.

Two thoughts I have so far are:

  1. When the client starts up and makes a stream connection, the server sends an initial message containing all your feature flags. Based on the stacktrace, the parse error is happening on that initial message. So I'm a little surprised that you're seeing it so often; I would expect it to only happen once per instance of your application, unless a network error is causing the stream connection to drop and be recreated. Is it possible that you're calling LaunchDarkly.init() more often than necessary, like once per active user session? That wouldn't account for the JSON error, but it would be quite inefficient; best practice is to keep a single client object up and running. If you do only have one client per app instance, and you're not running thousands of instances, then that might mean it's reconnecting a lot in which case I would suspect network trouble (although I think you would see log messages about reconnections in that case).

  2. Unfortunately, while the client does have a lot of optional debug-level log output, the particular thing we're looking for (the actual JSON data that failed to parse) is not one of the things it logs. But if you don't mind hacking the client code, I can show you where you could add that extra logging. Do you have a staging instance of your application where it'd be safe to make such a change (assuming the error can be reproduced there)?

magne4000 commented 6 years ago

1) We have a singleton handling ld_client, in which the init() is only called once at instanciation, so I'm pretty sure that we are good on that point. I'll add some more logging there just to be sure though.

2) This issue only happens to a limited percentage of our userbase though, and neither I or any of my colleagues are able to reproduce the issue. We do have a staging instance but with not enough user to reproduce the issue.

I assume that adding a try/catch around the JSON.parse call in the 'put' event listener would allow us to advance on this. If that's the case, I think we could try to release a version with extended debugging on that part in order to retrieve the full JSON in case of an Error.

eli-darkly commented 6 years ago

I've opened a support ticket for continued investigation - you should have received a link to it via email.

magne4000 commented 6 years ago

In the end, after adding the debugging information, it was the following error that was triggered a lot: LaunchDarklyStreamingError: Connection closed, reconnecting. It's not really an error in our use case, so we just ignored it, but I think that it should be discussed on wether you should keep triggering this as an error or not.

bwoskow-ld commented 5 years ago

I'm going to close this issue as it has been inactive for over a year. However, before I do so, I wanted to mention that in the time since this issue was filed, we released a first-class Electron SDK. If you're currently using our Node Server SDK in an Electron application, we recommend considering switching over to it.

https://docs.launchdarkly.com/docs/electron-sdk-reference