Clinic v0.6.2 / Node v8.9.4: Error: Invalid JSON (Unexpected "p" at position 24584 in state STOP) #9

darkpixel · 2018-02-04T03:16:25Z

This pops up after hanging at 'analyzing data' for a few seconds:

analysing data
events.js:183
      throw er; // Unhandled 'error' event
      ^

Error: Invalid JSON (Unexpected "p" at position 24584 in state STOP)
    at Parser.proto.charError (/home/aaron/code/mspdna-ssh/node_modules/jsonparse/jsonparse.js:90:16)
    at Parser.proto.write (/home/aaron/code/mspdna-ssh/node_modules/jsonparse/jsonparse.js:154:23)
    at Stream.<anonymous> (/home/aaron/code/mspdna-ssh/node_modules/JSONStream/index.js:21:12)
    at Stream.stream.write (/home/aaron/code/mspdna-ssh/node_modules/through/index.js:26:11)
    at TraceEventDecoder._transform (/home/aaron/code/mspdna-ssh/node_modules/@nearform/clinic-doctor/format/trace-event-decoder.js:114:19)
    at TraceEventDecoder.Transform._read (_stream_transform.js:186:10)
    at TraceEventDecoder.Transform._write (_stream_transform.js:174:12)
    at doWrite (_stream_writable.js:387:12)
    at writeOrBuffer (_stream_writable.js:373:5)
    at TraceEventDecoder.Writable.write (_stream_writable.js:290:11)
19:12:39 ⌂131% [aaron@ripley:~/code/mspdna-ssh] [mspdna] develop(+2861/-42)* 1 ±

The instructions say it would be super helpful if I tell clinic to upload some data to the cloud to help with debugging. I'm hesitant to do that on a private project that has SSH keys loaded into memory. What's "the cloud", where's the data going, and who gets to see it? ;)

The text was updated successfully, but these errors were encountered:

AndreasMadsen · 2018-02-04T09:26:40Z

Properly this is because you use Node v8.9.4. There are some issues with Node v8.9.4 that will be fixed in Node 8.10.0. Unfortunately, that hasn't been released yet. Please try Node v9.4.0 and see if that helps.

What's "the cloud", where's the data going, and who gets to see it? ;)

The cloud is our Amazon server that is in the US (@mafintosh confirm please) and only the clinic team gets to see it.

I think the more important question is what gets uploaded. There are three files, the information is not sensitive at all. The upload code is in https://github.com/nearform/node-clinic/blob/master/lib/tar-and-upload.js you can confirm yourself that it only uploads the clinic data. The clinic data itself contains three files:

{pid}.clinic-doctor-traceevent: A JSON file containing GC data and execution timing data (inspect it yourself). This is also the file that is partial.
{pid}.clinic-doctor-systeminfo: A JSON file (inspect it yourself).
{pid}.clinic-doctor-processstat: A protocol buffer file, containing samples of memory usage, cpu usage, delay, and number of handles. You can see the schema here: https://github.com/nearform/node-clinic-doctor/blob/master/format/process-stat.proto

Could you tell me if you have any files called node_trace.2.log?

mcollina · 2018-02-04T09:45:36Z

How about we put that explanation of the files being uploaded into the README? Seems a valid question.

darkpixel · 2018-02-04T18:17:38Z

Thanks @AndreasMadsen. I updated to Node 9.5.0 simply because that was the latest version in the 9x tree from nodesource. Let me know if I need to specifically downgrade to 9.4.0 for testing and I'll do it.

I was testing with the 'ssh module' component of my stack earlier, but moved on to doing some work on the 'receiver module' late yesterday, so I decided to test clinic with it.

I got a similar error:

^Canalysing data
events.js:137
      throw er; // Unhandled 'error' event
      ^

Error: Unexpected LEFT_BRACE("{") in state KEY
    at Parser.proto.parseError (/home/aaron/code/mspdna-receiver/node_modules/jsonparse/jsonparse.js:321:16)
    at Parser.proto.onToken (/home/aaron/code/mspdna-receiver/node_modules/jsonparse/jsonparse.js:391:19)
    at Parser.parser.onToken (/home/aaron/code/mspdna-receiver/node_modules/JSONStream/index.js:126:12)
    at Parser.proto.write (/home/aaron/code/mspdna-receiver/node_modules/jsonparse/jsonparse.js:134:28)
    at Stream.<anonymous> (/home/aaron/code/mspdna-receiver/node_modules/JSONStream/index.js:21:12)
    at Stream.stream.write (/home/aaron/code/mspdna-receiver/node_modules/through/index.js:26:11)
    at TraceEventDecoder._transform (/home/aaron/code/mspdna-receiver/node_modules/@nearform/clinic-doctor/format/trace-event-decoder.js:114:19)
    at TraceEventDecoder.Transform._read (_stream_transform.js:185:10)
    at TraceEventDecoder.Transform._write (_stream_transform.js:173:12)
    at doWrite (_stream_writable.js:407:12)
10:00:42 ⌂115% [aaron@ripley:~/code/mspdna-receiver] [mspdna] develop(+2570/-170)* 1 ± node --version
v9.5.0

The single run of clinic produced 10 .clinic-doctor folders. Running clinic upload suggests I run clinic upload 13242.clinic-doctor. That folder doesn't exist, so I think the text is just an example. If it's tracking a 'last run' or something, then it mis-detected it.

I'm guessing the multiple folders are for each process spawned by the cluster module which I was using in both my ssh module and receiver module. I decided now would be a good time to migrate away from it, so I ripped it out and I can't seem to duplicate any of the errors. But the end result is a report that says there was an unknown issue.

I'm going to rip the cluster module out of my ssh module and try testing again with that. When I ran clinic against my ssh module I was able to get a report back occasionally with an event loop delay when my box was under a ton of load.

davidmarkclements · 2018-02-04T18:21:42Z

ahhhh so this tells me we need to either

Support the cluster module
Be explicit that node-clinic is for single process profiling (as is clinic flame/0x and I assume our additional upcoming tools)

davidmarkclements · 2018-02-04T18:22:15Z

In the second case we could detect usage of the cluster module and then exit with an error

darkpixel · 2018-02-04T18:32:48Z

After hammering away without the cluster module, I can't seem to hit any errors in my ssh module. In my receiver module which is basically an express app that received large (up to ~2 MB) chunks of JSON data, clinic continually reports that "Unknown issue" from the screenshot. Any idea what that might be?

davidmarkclements · 2018-02-04T18:35:34Z

oh that's awesome - the unknown issue means you've either found a new problem or you've found an edge case that we could use to tune our statistical algorithms. Can you provide an isolated case?

darkpixel · 2018-02-04T18:45:21Z

Sure--you want me to run it and upload the data? Or are you asking if I might have an idea of what the unknown issue is?

darkpixel · 2018-02-04T18:47:34Z

Uploaded: ce48307f83bee7e5cc865e20109f1d77b18b2e847f9cd06c25e2852a5e98cbf2

AndreasMadsen · 2018-02-08T08:08:36Z

I looked at the data, it appears that you have both an I/O issue and a GC issue. So that is confusing our classifier a bit.

Regarding the cluster issue, in terms of supporting clusters there are two options:

we can just profile the master process (easy, but properly not what you want)
we can profile all processes (also easy, but requires trace_events: add file pattern cli option nodejs/node#18480) – What will be confusing is that by default the master process will be analyzed, so the user will have to manually call clinic doctor --visualize-only pid.clinic-doctor to analyze the other processes.

AndreasMadsen · 2018-02-09T20:37:40Z

Ref: https://github.com/nearform/node-clinic-doctor/issues/102 (cluster issue)

mafintosh · 2018-03-07T10:10:52Z

Node 8.10.0 has been released and clinic seems to run great on it. The cluster issue is still relevant.

AndreasMadsen · 2018-03-07T11:34:05Z

@mafintosh The nodejs/node#14802 issue is also still relevant and could be the cause of some of these issues.

davisjam · 2018-04-25T03:16:41Z

Similar issue on v9.11.1 using the Node-DC-EIS workload.

(23:12:38) jamie@woody ~/Desktop/node-profiling/benchmarks/node-dc/Node-DC-EIS/Node-DC-EIS-cluster $ export CPU_COUNT=1; ~/Desktop/floss/node-clinic/bin.js doctor -- node server-cluster.js 
Warning: Trace event is an experimental feature and could change at any time.
********************************
Server running at port: 9000
********************************
Setting up cluster with 1 Master (pid: 8843) and 1 workers..
Warning: Trace event is an experimental feature and could change at any time.
Worker:8854 is online
(node:8854) DeprecationWarning: `open()` is deprecated in mongoose >= 4.11.0, use `openUri()` instead, or set the `useMongoClient` option if using `connect()` or `createConnection()`. See http://mongoosejs.com/docs/connections.html#use-mongo-client
Mongoose connected to the database
Constructing list of first names
Constructing list of last names
Constructing list of Addresses
(node:8854) DeprecationWarning: Mongoose: mpromise (mongoose's default promise library) is deprecated, plug in your own promise library instead: http://mongoosejs.com/docs/promises.html
^Canalysing data
events.js:165
      throw er; // Unhandled 'error' event
      ^

Error: Unexpected COMMA(",") in state VALUE
    at Parser.proto.parseError (/home/jamie/Desktop/floss/node-clinic/node_modules/jsonparse/jsonparse.js:321:16)
    at Parser.proto.onToken (/home/jamie/Desktop/floss/node-clinic/node_modules/jsonparse/jsonparse.js:382:19)
    at Parser.parser.onToken (/home/jamie/Desktop/floss/node-clinic/node_modules/JSONStream/index.js:126:12)
    at Parser.proto.write (/home/jamie/Desktop/floss/node-clinic/node_modules/jsonparse/jsonparse.js:139:34)
    at Stream.<anonymous> (/home/jamie/Desktop/floss/node-clinic/node_modules/JSONStream/index.js:21:12)
    at Stream.stream.write (/home/jamie/Desktop/floss/node-clinic/node_modules/through/index.js:26:11)
    at TraceEventDecoder._transform (/home/jamie/Desktop/floss/node-clinic/node_modules/@nearform/clinic-doctor/format/trace-event-decoder.js:114:19)
    at TraceEventDecoder.Transform._read (_stream_transform.js:185:10)
    at TraceEventDecoder.Transform._write (_stream_transform.js:173:12)
    at doWrite (_stream_writable.js:410:12)
Emitted 'error' event at:
    at Parser.parser.onError (/home/jamie/Desktop/floss/node-clinic/node_modules/JSONStream/index.js:140:12)
    at Parser.proto.parseError (/home/jamie/Desktop/floss/node-clinic/node_modules/jsonparse/jsonparse.js:321:8)
    at Parser.proto.onToken (/home/jamie/Desktop/floss/node-clinic/node_modules/jsonparse/jsonparse.js:382:19)
    [... lines matching original stack trace ...]
    at TraceEventDecoder.Transform._write (_stream_transform.js:173:12)

BridgeAR · 2018-08-31T14:11:44Z

Neither bubbleprof nor doctor support cluster and will now throw an error if cluster.fork() is called.

Therefore I am closing this as resolved.

BridgeAR closed this as completed Aug 31, 2018

BridgeAR mentioned this issue Sep 24, 2018

Doctor has found an unknown issue - Node version 8.11.2 #60

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Clinic v0.6.2 / Node v8.9.4: Error: Invalid JSON (Unexpected "p" at position 24584 in state STOP) #9

Clinic v0.6.2 / Node v8.9.4: Error: Invalid JSON (Unexpected "p" at position 24584 in state STOP) #9

darkpixel commented Feb 4, 2018

AndreasMadsen commented Feb 4, 2018 •

edited

Loading

mcollina commented Feb 4, 2018

darkpixel commented Feb 4, 2018

davidmarkclements commented Feb 4, 2018

davidmarkclements commented Feb 4, 2018

darkpixel commented Feb 4, 2018

davidmarkclements commented Feb 4, 2018

darkpixel commented Feb 4, 2018

darkpixel commented Feb 4, 2018

AndreasMadsen commented Feb 8, 2018

AndreasMadsen commented Feb 9, 2018

mafintosh commented Mar 7, 2018

AndreasMadsen commented Mar 7, 2018

davisjam commented Apr 25, 2018

BridgeAR commented Aug 31, 2018

Clinic v0.6.2 / Node v8.9.4: Error: Invalid JSON (Unexpected "p" at position 24584 in state STOP) #9

Clinic v0.6.2 / Node v8.9.4: Error: Invalid JSON (Unexpected "p" at position 24584 in state STOP) #9

Comments

darkpixel commented Feb 4, 2018

AndreasMadsen commented Feb 4, 2018 • edited Loading

mcollina commented Feb 4, 2018

darkpixel commented Feb 4, 2018

davidmarkclements commented Feb 4, 2018

davidmarkclements commented Feb 4, 2018

darkpixel commented Feb 4, 2018

davidmarkclements commented Feb 4, 2018

darkpixel commented Feb 4, 2018

darkpixel commented Feb 4, 2018

AndreasMadsen commented Feb 8, 2018

AndreasMadsen commented Feb 9, 2018

mafintosh commented Mar 7, 2018

AndreasMadsen commented Mar 7, 2018

davisjam commented Apr 25, 2018

BridgeAR commented Aug 31, 2018

AndreasMadsen commented Feb 4, 2018 •

edited

Loading