asciidoctor / asciidoctor-kroki

Asciidoctor.js extension to convert diagrams to images using Kroki!
https://kroki.io/
MIT License
146 stars 47 forks source link

Sporadic "Unexpected end of JSON input" for vega-lite diagram #115

Closed stenzengel closed 3 years ago

stenzengel commented 4 years ago

Sometimes, (I could not find the cause) there is an error "Unexpected end of JSON input" for vega-lite files. It seems to correlate with the length of the file, but even setting :kroki-http-method: post did not solve the problem. I'm not sure if it is really a length problem. Perhaps it is some concurrency problem or vega-lite problem or even a local problem?

Can you reproduce the problem?

Example (somewhat lengthy, but this seems to be have impact):

= Test
:kroki-fetch-diagram:

[vegalite]
....
{
    "$schema": "https://vega.github.io/schema/vega-lite/v4.json",
    "data": {
        "values": [
            {
                "a": "B",
                "b": 1.2
            },
            {
                "a": "B",
                "b": 1.2
            },
            {
                "a": "B",
                "b": 1.2
            },
            {
                "a": "B",
                "b": 1.2
            },
            {
                "a": "B",
                "b": 1.2
            },
            {
                "a": "A",
                "b": 2.1
            },
            {
                "a": "B",
                "b": 1.2
            },
            {
                "a": "A",
                "b": 2.1
            },
            {
                "a": "B",
                "b": 1.2
            },
            {
                "a": "A",
                "b": 2.1
            },
            {
                "a": "B",
                "b": 1.2
            },
            {
                "a": "A",
                "b": 2.1
            },
            {
                "a": "B",
                "b": 1.2
            },
            {
                "a": "A",
                "b": 2.1
            },
            {
                "a": "B",
                "b": 1.2
            },
            {
                "a": "A",
                "b": 2.1
            },
            {
                "a": "B",
                "b": 1.2
            },
            {
                "a": "A",
                "b": 2.1
            },
            {
                "a": "B",
                "b": 1.2
            },
            {
                "a": "A",
                "b": 2.1
            },
            {
                "a": "B",
                "b": 1.2
            },
            {
                "a": "C",
                "b": 0.3
            }
        ]
    },
    "encoding": {
        "x": {
            "field": "a",
            "type": "ordinal"
        },
        "y": {
            "field": "b",
            "type": "quantitative"
        }
    },
    "mark": "bar"
}
....

Current behavior:

Skipping vegalite block. GET https://kroki.io/vegalite/svg/eNrtk7EOgjAQhuf2KczFUVtFJzf1MYzDIRWqBRSORkN4d9uCidHVxMWl6X_5_u-mazmDcX3IVI6wGkFGdKlXUlqVokg1ZU0sdCl7IEynRpOSdilOdVnAxNUTJN9tOWNg0TSqdmnnEvMjNwzmjWd9il2ai8iHbvJ7av1KRWL-d_1d33RtX6mZWATKPXseYFDFoUx0kT4v6DZ8GBy1MolXYK8Aul-Uz2XlCmiAD_vg_tmJ3zrXBgvShKStCsVhfY7VOfBYAe8emR-p3Q== - error; reason: Unexpected end of JSON input

Some remarks:

Very strange! Do you have an idea, how to narrow down the problem?

ggrossetie commented 4 years ago

Very strange! Do you have an idea, how to narrow down the problem?

The error is thrown by: https://github.com/Mogztter/asciidoctor-kroki/blob/38edf9eacf376f605e970172fd6eb88f58769e50/src/http/http-client.js#L30

But I think the root cause might be here: https://github.com/Mogztter/unxhr/blob/5644c255d0ef6986a74489c097eba51a7dc17b93/lib/XMLHttpRequest.js#L484

As you can see we are using JSON.parse(output.toString('utf8')) and the error seems to indicate that output is not a JSON. I would advice to add a console.log('output', output.toString('utf8')) just before const result = JSON.parse(output.toString('utf8')).

For reference, we are using unxhr (based on node-XMLHttpRequest) to execute synchronous HTTP requests.

stenzengel commented 4 years ago

Have you an idea, what the problem is?

ggrossetie commented 4 years ago

I just tried and it's working fine on my machine. Are you behind a corporate proxy? Do you get an image from https://kroki.io/vegalite/svg/eNrtk7EOgjAQhuf2KczFUVtFJzf1MYzDIRWqBRSORkN4d9uCidHVxMWl6X_5_u-mazmDcX3IVI6wGkFGdKlXUlqVokg1ZU0sdCl7IEynRpOSdilOdVnAxNUTJN9tOWNg0TSqdmnnEvMjNwzmjWd9il2ai8iHbvJ7av1KRWL-d_1d33RtX6mZWATKPXseYFDFoUx0kT4v6DZ8GBy1MolXYK8Aul-Uz2XlCmiAD_vg_tmJ3zrXBgvShKStCsVhfY7VOfBYAe8emR-p3Q==

unxhr should not return '', maybe your system cannot spawn a Node.js child process? You can try to reproduce this issue using only unxhr:

const XMLHttpRequest = require('unxhr').XMLHttpRequest
const xhr = new XMLHttpRequest()

let data = ''
let status = -1

xhr.open('GET', 'https://kroki.io/vegalite/svg/eNrtk7EOgjAQhuf2KczFUVtFJzf1MYzDIRWqBRSORkN4d9uCidHVxMWl6X_5_u-mazmDcX3IVI6wGkFGdKlXUlqVokg1ZU0sdCl7IEynRpOSdilOdVnAxNUTJN9tOWNg0TSqdmnnEvMjNwzmjWd9il2ai8iHbvJ7av1KRWL-d_1d33RtX6mZWATKPXseYFDFoUx0kT4v6DZ8GBy1MolXYK8Aul-Uz2XlCmiAD_vg_tmJ3zrXBgvShKStCsVhfY7VOfBYAe8emR-p3Q==', false)

xhr.addEventListener('load', function () {
  status = this.status
  if (status === 200) {
    data = this.responseText
  }
})
xhr.send()

console.log('status', status)
console.log('data', data)

You should try others URI as well. What version of node are you using?

stenzengel commented 4 years ago

Answers to you questions:

But when I run your test code with ts-node (instead of node), I get the same error (SyntaxError: Unexpected end of JSON input) as originally. Actually I run a TypeScript file with ts-node to convert my asciidoc files and running with ts-node seems to be the root cause of my problem. Therefor, I converted my TypeScript file for converting asciidoc files back to JavaScript and run with node (instead of ts-node). Et voilà, the SyntaxError: Unexpected end of JSON input is gone (I still have one SyntaxError: Unexpected token J in JSON at position 0 for another diagram, but this should be the vega-lite inconsistency mentioned before).

Thanks for your help. Now I have to find out, why it does not work with ts-node... Do you have an idea?

I don't think anymore, that this issue is a problem of asciidoctor-kroki. If you agree, I (or you) can close this issue.

stenzengel commented 4 years ago

As you supposed, the problem seems to be the creation of a new child process when using ts-node. At least, there is a similar question here: https://stackoverflow.com/questions/52569406/invoke-a-child-process-via-fork-when-using-ts-node

FYI: I do not have time the next two weeks, but afterwards, if you want to support ts-node, too.

ggrossetie commented 3 years ago

Thanks for the follow-up.

Now I have to find out, why it does not work with ts-node... Do you have an idea?

No sorry, I'm not a big user of TypeScript.

I don't think anymore, that this issue is a problem of asciidoctor-kroki. If you agree, I (or you) can close this issue.

Yes, I agree. I think you should open an new issue at ts-node with a reproduction case. You can take a look at what unxhr is doing to create as simple reproduction case.

Untested code but it should be roughly:

main.js

const data = 'hello'
const output = require('child_process').execSync(`"${process.argv[0]}" "${__dirname}/output.js"`, { stdio: ['pipe', 'pipe', 'pipe'], input: data })
const result = JSON.parse(output.toString('utf8'))

output.js

(async () => {
  try {
    const encoding = 'utf-8'
    let data
    if (process.stdin.isTTY) {
      // Even though executed by name, the first argument is still "node",
      // the second the script name. The third is the string we want.
      data = Buffer.from(process.argv[2] || '', encoding)
      console.log(JSON.stringify({result: data}))
    } else {
      // Accepting piped content. E.g.:
      // echo "pass in this string as input" | ./example-script
      data = ''
      process.stdin.setEncoding(encoding)
      process.stdin.on('readable', function () {
        let chunk = process.stdin.read()
        while (chunk) {
          data += chunk
          chunk = process.stdin.read()
        }
      })
      process.stdin.on('end', async function () {
        // There will be a trailing \n from the user hitting enter. Get rid of it.
        data = data.replace(/\n$/, '')
        console.log(JSON.stringify({result: data}))
      })
    }
  } catch (e) {
    console.log(JSON.stringify({ error: e }))
  }
})()
ggrossetie commented 3 years ago

Closing :wink:

stenzengel commented 3 years ago

@Mogztter I have looked at this problem again. The cause is, as you suspected, the line where execSync() is called (https://github.com/Mogztter/unxhr/blob/5644c255d0ef6986a74489c097eba51a7dc17b93/lib/XMLHttpRequest.js#L484)

The problem is the parameter process.argv[0]. When started via ts-node its value is ...\node_modules\ts-node\dist\bin.js, while when started via node it has for example the value C:\Program Files\nodejs\node.exe.

The best workaround I have found is executing my TypeScript helper file asciidoctor.ts (which runs the "asciidoctor.js" processor with the extension "asciidoctor-kroki") with node -r ts-node/register asciidoctor.ts *.adoc instead of the shorter form ts-node asciidoctor.ts *.adoc as described in the "ts-node" readme (https://github.com/TypeStrong/ts-node#programmatic). In this case process.argv[0] is correct. (Another workaround is to precompile the TS-file to JavaScript and run the JS-file with node),

I don't know, if there is a generic and safe solution to replace process.argv[0] in XMLHttpRequest.js with something always pointing to "node.js". This could avoid confusion in the future for others using "ts-node" with "asciidoctor-kroki". If not, at least there is an easy workaround...

stenzengel commented 3 years ago

@Mogztter Using fork() instead of execSync() and omitting the parameter process.argv[0] seems to work. I.e. both forms (node -r ts-node/register asciidoctor.ts *.adoc and ts-node asciidoctor.ts *.adoc) work, when I change line 481 in XMLHttpRequest.js from

const output = require('child_process').execSync(`"${process.argv[0]}" "${__dirname}/request.js" \

to

const output = require('child_process').fork(`"${__dirname}/request.js" \

I do not know if everything else behaves the same as before (I had a only quick look at https://www.freecodecamp.org/news/node-js-child-processes-everything-you-need-to-know-e69498fe970a), but if you like I can create a PR.

ggrossetie commented 3 years ago

Hey @stenzengel

As far as I know, fork is not synchronous. We might need a special case when using ts-node. Feel free to open an issue at https://github.com/Mogztter/unxhr. In the worst case scenario, we can still document the workaround you found.

stenzengel commented 3 years ago

@Mogztter I have found the information that fork is only synchronous (https://stackoverflow.com/questions/56334455/is-there-synchronous-version-of-child-process-fork-in-node-js), but I am not familiar with node's child_process

ggrossetie commented 3 years ago

Oh I didn't know! Could you please open an issue at https://github.com/Mogztter/unxhr so we can continue this discussion and try to fix this issue using fork?