search

Glimpse / Home

Project Glimpse: Node Edition - Spend less time debugging and more time developing.
http://node.getglimpse.com
Other
252 stars 9 forks source link

Cannot read property offset of undefined #107

Closed Intellicode closed 7 years ago

Intellicode commented 7 years ago

I'm using the following software:

Node 6.9.2 graphql-server-express 0.7.2 express 4.15.2 @glimpse/glimpse 0.20.8

The request is a graphql mutation, if it helps anything:

/project-name/node_modules/@glimpse/glimpse-agent-node/release/configuration/DateTimeValue.js:19
        var valueOffset = value.offset;
                               ^

TypeError: Cannot read property 'offset' of undefined
    at DateTimeValue.diff (/project-name/node_modules/@glimpse/glimpse-agent-node/release/configuration/DateTimeValue.js:19:32)
    at ClientRequestInspector.onResponseEnd (/project-name/node_modules/@glimpse/glimpse-agent-node/release/inspectors/ClientRequestInspector.js:280:62)
    at Object.listeners._a.(anonymous function) [as listener] (/project-name/node_modules/@glimpse/glimpse-agent-node/release/inspectors/ClientRequestInspector.js:135:95)
    at Tracing.publish (/project-name/node_modules/@glimpse/glimpse-agent-node/release/tracing/Tracing.js:31:26)
    at HttpClientProxy.publishResponseEndEvent (/project-name/node_modules/@glimpse/glimpse-agent-node/release/tracing/module_instrumentors/HttpClientProxy.js:31:27)
    at IncomingMessage.<anonymous> (/project-name/node_modules/@glimpse/glimpse-agent-node/release/tracing/module_instrumentors/HttpClientProxy.js:65:30)
    at IncomingMessage.wrappedCallback (/project-name/node_modules/@glimpse/glimpse-agent-node/release/async-track/async-track.js:293:33)
    at emitNone (events.js:91:20)
    at IncomingMessage.emit (events.js:185:7)
    at endReadableNT (_stream_readable.js:974:12)
    at wrappedCallback (/project-name/node_modules/@glimpse/glimpse-agent-node/release/async-track/async-track.js:293:33)
    at _combinedTickCallback (internal/process/next_tick.js:74:11)
    at process._tickCallback (internal/process/next_tick.js:98:9)
philliphoff commented 7 years ago

Thanks for reporting this issue! Do you see the error on every request, only on certain requests, or only intermittently with the same request?

If you happen to have (or can create) a small repro app that you can point me to, that'd be great. Otherwise, I'll take a crack at creating one and trying to investigate how that error shows up.

philliphoff commented 7 years ago

I tried this scenario using both a pre-built sample as well as one of my own, but wasn't able to reproduce the error you're seeing. Any information about the circumstances under which you're seeing issues would be really helpful. Thanks!

Intellicode commented 7 years ago

Sorry, I was at a conference for the past 2 days, but I'll try to see if I can pinpoint exactly what kind of request it was. Unfortuntately, our code base is not opensource, but maybe I can narrow it down to a small test case. I'll post an update as soon as I can!

mike-kaufman commented 7 years ago

@Intellicode - From looking at our code here, it looks like what is happening is in your code, you're calling response.end() before calling request.end().

Do you see any cases where this is occurring? We obviously need to harden our code paths against this.

Intellicode commented 7 years ago

@mike-kaufman do you suspect our code to do this while making a request to an external service? We use basic express.js functionality to handle client requests/responses and a isomorphic-fetch library to perform requests to other services.

mike-kaufman commented 7 years ago

do you suspect our code to do this while making a request to an external service?

So, from reading through our code, it looks like the only way to see that exception is when response.end() occurs before request.end() for a node http.request() call. My guess is isomorphic-fetch is doing this for some reason. If you have some stripped-down repro code, that'd be a great help. If not, we'll try & replicate here.

Intellicode commented 7 years ago

I can confirm, it has something to do with isomorphic-fetch. If I comment out the code, it won't throw the error. However, I have not been able to reproduce it in a example repo yet. My guess is that it has something to do with apollo graphql as well.

Intellicode commented 7 years ago

I managed to get a more interesting error, apparently our fetch call is failing because of glimpse:

TypeError: header.substring is not a function
    at Function.HttpHelper.parseContentType (/project-dir/node_modules/@glimpse/glimpse-agent-node/release/util/HttpHelper.js:263:27)
    at Object.createMultiPartFormSummarizer (/project-dir/node_modules/@glimpse/glimpse-agent-node/release/util/MultiPartFormSummarizer.js:7:47)
    at ClientRequestInspector.onRequestDataSent (/project-dir/node_modules/@glimpse/glimpse-agent-node/release/inspectors/ClientRequestInspector.js:202:80)
    at Object.listeners._a.(anonymous function) [as listener] (/project-dir/node_modules/@glimpse/glimpse-agent-node/release/inspectors/ClientRequestInspector.js:130:100)
    at Tracing.publish (/project-dir/node_modules/@glimpse/glimpse-agent-node/release/tracing/Tracing.js:31:26)
    at HttpClientProxy.publishRequestDataSentEvent (/project-dir/node_modules/@glimpse/glimpse-agent-node/release/tracing/module_instrumentors/HttpClientProxy.js:16:27)
    at ClientRequest.req.write (/project-dir/node_modules/@glimpse/glimpse-agent-node/release/tracing/module_instrumentors/HttpClientProxy.js:91:26)
    at /project-dir/node_modules/node-fetch/index.js:240:8
    at new wrappedPromise (/project-dir/node_modules/async-listener/index.js:408:16)
    at new Fetch (/project-dir/node_modules/node-fetch/index.js:49:9)
    at Fetch (/project-dir/node_modules/node-fetch/index.js:37:10)
    at module.exports (/project-dir/node_modules/isomorphic-fetch/fetch-npm-node.js:8:19)
    at somethingConnector.dispatchEvent (/project-dir/src/services/somethings/connector.js:76:12)
    at somethingSource.dispatchInSomeEvent (/project-dir/src/services/somethings/models/somethingSource.js:52:27)
    at dispatchsomethingEvent (/project-dir/src/services/events/resolvers/mutation.js:13:47)
    at resolveOrError (/project-dir/node_modules/graphql/execution/execute.js:474:12)
/project-dir/node_modules/@glimpse/glimpse-agent-node/release/configuration/DateTimeValue.js:19
        var valueOffset = value.offset;
                               ^

TypeError: Cannot read property 'offset' of undefined
    at DateTimeValue.diff (/project-dir/node_modules/@glimpse/glimpse-agent-node/release/configuration/DateTimeValue.js:19:32)
    at ClientRequestInspector.onResponseEnd (/project-dir/node_modules/@glimpse/glimpse-agent-node/release/inspectors/ClientRequestInspector.js:280:62)
    at Object.listeners._a.(anonymous function) [as listener] (/project-dir/node_modules/@glimpse/glimpse-agent-node/release/inspectors/ClientRequestInspector.js:135:95)
    at Tracing.publish (/project-dir/node_modules/@glimpse/glimpse-agent-node/release/tracing/Tracing.js:31:26)
    at HttpClientProxy.publishResponseEndEvent (/project-dir/node_modules/@glimpse/glimpse-agent-node/release/tracing/module_instrumentors/HttpClientProxy.js:31:27)
    at IncomingMessage.<anonymous> (/project-dir/node_modules/@glimpse/glimpse-agent-node/release/tracing/module_instrumentors/HttpClientProxy.js:65:30)
    at IncomingMessage.wrappedCallback (/project-dir/node_modules/@glimpse/glimpse-agent-node/release/async-track/async-track.js:293:33)
    at emitNone (events.js:91:20)
    at IncomingMessage.emit (events.js:185:7)
    at endReadableNT (_stream_readable.js:974:12)
    at wrappedCallback (/project-dir/node_modules/@glimpse/glimpse-agent-node/release/async-track/async-track.js:293:33)
    at _combinedTickCallback (internal/process/next_tick.js:74:11)
    at process._tickCallback (internal/process/next_tick.js:98:9)

I checked the variable header, and it is actually an array and not a string.

(actual module names have been altered)

evanderkoogh commented 7 years ago

I seem to having exactly the same problem: We are using node-fetch directly which isomorphic-fetch is using as well. The error does not occur on pages where we do not make any requests. So I am relatively confident the issues is with node-fetch and/or glimpse.

They might be doing something wrong, but that's no reason for Glimpse to crash and burn at the very least ;)

/Users/evanderkoogh/Documents/projects/bitgenics/linc/linc-cli/node_modules/@glimpse/glimpse-agent-node/release/configuration/DateTimeValue.js:19
        var valueOffset = value.offset;
                               ^

TypeError: Cannot read property 'offset' of undefined
    at DateTimeValue.diff (/Users/evanderkoogh/Documents/projects/bitgenics/linc/linc-cli/node_modules/@glimpse/glimpse-agent-node/release/configuration/DateTimeValue.js:19:32)
    at ClientRequestInspector.onResponseEnd (/Users/evanderkoogh/Documents/projects/bitgenics/linc/linc-cli/node_modules/@glimpse/glimpse-agent-node/release/inspectors/ClientRequestInspector.js:280:62)
    at Object.listeners._a.(anonymous function) [as listener] (/Users/evanderkoogh/Documents/projects/bitgenics/linc/linc-cli/node_modules/@glimpse/glimpse-agent-node/release/inspectors/ClientRequestInspector.js:135:95)
    at Tracing.publish (/Users/evanderkoogh/Documents/projects/bitgenics/linc/linc-cli/node_modules/@glimpse/glimpse-agent-node/release/tracing/Tracing.js:31:26)
    at HttpClientProxy.publishResponseEndEvent (/Users/evanderkoogh/Documents/projects/bitgenics/linc/linc-cli/node_modules/@glimpse/glimpse-agent-node/release/tracing/module_instrumentors/HttpClientProxy.js:31:27)
    at IncomingMessage.<anonymous> (/Users/evanderkoogh/Documents/projects/bitgenics/linc/linc-cli/node_modules/@glimpse/glimpse-agent-node/release/tracing/module_instrumentors/HttpClientProxy.js:65:30)
    at IncomingMessage.wrappedCallback (/Users/evanderkoogh/Documents/projects/bitgenics/linc/linc-cli/node_modules/@glimpse/glimpse-agent-node/release/async-track/async-track.js:293:33)
    at emitNone (events.js:91:20)
    at IncomingMessage.emit (events.js:185:7)
    at endReadableNT (_stream_readable.js:974:12)
mike-kaufman commented 7 years ago

@Intellicode -

For this:

TypeError: header.substring is not a function
    at Function.HttpHelper.parseContentType (/project-dir/node_modules/@glimpse/glimpse-agent-node/release/util/HttpHelper.js:263:27)
    at Object.createMultiPartFormSummarizer (/project-dir/node_modules/@glimpse/glimpse-agent-node/release/util/MultiPartFormSummarizer.js:7:47)

In this case, what is in the array?

mike-kaufman commented 7 years ago

@Intellicode , @evanderkoogh -

For TypeError: Cannot read property 'offset' of undefined errors, I've got a fix for this, it should be out on npm early next week after we get the latest batch of changes tested & verified.

Intellicode commented 7 years ago

@mike-kaufman, it contained ['application/json'] That error might explain why request.end was not called, because it crashed due to the substring call.

evanderkoogh commented 7 years ago

No worries @mike-kaufman. If you want to throw a fix my way to test it let me know. More than happy to help out.

mike-kaufman commented 7 years ago

Fix should be coming out to npm a few days. I tried to replicate this behavior w/ isomorphic fetch and I couldn't.

If you want to test a pre-release build from our alpha feed, you can do this:

npm config set @glimpse:registry=https://www.myget.org/F/g-alpha/npm/ npm install @glimpse/glimpse npm ls @glimpse/glimpse # this should say v0.21.3 or higher.

Intellicode commented 7 years ago

@mike-kaufman Seems to fix the issue (in my case), thanks!

evanderkoogh commented 7 years ago

I will try to squeeze this in between jobs, but training for the next 2 days so probably won't be able to get it tested before the weekend. Will let you know what I find

mike-kaufman commented 7 years ago

Fix for this is availabe on NPM now with glimpse version 0.21.5.