The render with keepAlive should provide full output if process crashes

[pofider]

The output of the jsreport init is crucial when analyzing the reason of failing jsreport render --keepAlive

[tskimmett]

I'm getting an exception from the call to render if the --keepAlive argument is set. If I call render without --keepAlive, it works fine. I came to this finding after trying to determine why my aspnetcore application does not render PDFs when in a docker container hosted in AWS, yet it works perfectly fine in the container on my local machine, using the exact same Dockerfile. Can you provide any insight into this?

without --keepAlive

root@74033afffebd:/tmp/jsreport/dotnet/binary-default-linux-1.10.0.0# ./jsreport.exe  render --template.engine=none --template.recipe=phantom-pdf --template.content=test.html --out=out.pdf --verbose
looking for previously daemonized instance in: /tmp/jsreport/cli/sock/workerSock cwd: /tmp/jsreport/dotnet/binary-default-linux-1.10.0.0
there is no previously daemonized instance in: /tmp/jsreport/cli/sock/workerSock cwd: /tmp/jsreport/dotnet/binary-default-linux-1.10.0.0
using jsreport instance passed from options
disabling express extension..
2018-06-11T01:51:57.697Z - info: Initializing jsreport@1.10.0 in development mode using configuration file: none
2018-06-11T01:51:57.702Z - info: Using extension import-export
2018-06-11T01:51:57.704Z - info: Using extension templates
2018-06-11T01:51:57.705Z - info: Using extension jsrender
2018-06-11T01:51:57.705Z - info: Using extension authentication
2018-06-11T01:51:57.706Z - debug: Extension authentication was disabled
2018-06-11T01:51:57.706Z - info: Using extension cli
2018-06-11T01:51:57.707Z - info: Using extension handlebars
2018-06-11T01:51:57.707Z - info: Using extension debug
2018-06-11T01:51:57.708Z - debug: Extension express is disabled, skipping
2018-06-11T01:51:57.708Z - info: Using extension fop-pdf
2018-06-11T01:51:57.709Z - info: Using extension tags
2018-06-11T01:51:57.710Z - info: Using extension phantom-pdf
2018-06-11T01:51:57.712Z - info: Using extension fs-store
2018-06-11T01:51:57.712Z - debug: Extension fs-store was disabled
2018-06-11T01:51:57.712Z - info: Using extension authorization
2018-06-11T01:51:57.713Z - debug: Extension authorization was disabled
2018-06-11T01:51:57.713Z - info: Using extension images
2018-06-11T01:51:57.714Z - info: Using extension child-templates
2018-06-11T01:51:57.715Z - info: Using extension browser-client
2018-06-11T01:51:57.715Z - info: Using extension licensing
2018-06-11T01:51:57.716Z - info: Using extension data
2018-06-11T01:51:57.717Z - info: Using extension text
2018-06-11T01:51:57.718Z - info: Using extension reports
2018-06-11T01:51:57.719Z - info: Using extension resources
2018-06-11T01:51:57.719Z - info: Using extension base
2018-06-11T01:51:57.720Z - info: Using extension studio
2018-06-11T01:51:57.720Z - info: Using extension html-to-xlsx
2018-06-11T01:51:57.722Z - info: Using extension scripts
2018-06-11T01:51:57.723Z - info: Using extension assets
2018-06-11T01:51:57.724Z - info: Using extension scheduling
2018-06-11T01:51:57.725Z - info: Using extension xlsx
2018-06-11T01:51:57.726Z - info: Using extension sample-template
2018-06-11T01:51:57.726Z - debug: Creating samples is disabled
2018-06-11T01:51:57.726Z - info: Using extension public-templates
2018-06-11T01:51:57.727Z - debug: Extension public-templates was disabled
2018-06-11T01:51:57.743Z - info: Creating memory store
2018-06-11T01:51:57.774Z - info: Verifying license key free
2018-06-11T01:51:57.776Z - info: Using free license
2018-06-11T01:51:57.779Z - info: reporter initialized
starting rendering process..
Output configured to: /tmp/jsreport/dotnet/binary-default-linux-1.10.0.0/out.pdf
rendering with options:
{
  "template": {
    "engine": "none",
    "recipe": "phantom-pdf",
    "content": "<h1>Hello World</h1>\n"
  }
}
2018-06-11T01:51:57.783Z - info: Starting rendering request 1 (user: null) requestId=1
2018-06-11T01:51:57.785Z - info: Rendering anonymous template { recipe:phantom-pdf,engine:none} requestId=1
2018-06-11T01:51:57.785Z - debug: Data item not defined for this template. requestId=1
2018-06-11T01:51:57.791Z - debug: Resources not defined for this template. requestId=1
2018-06-11T01:51:57.792Z - debug: Base url not specified, skipping its injection. requestId=1
2018-06-11T01:51:57.793Z - debug: Rendering engine none requestId=1
2018-06-11T01:51:57.819Z - debug: Compiled template not found in the cache, compiling timestamp=Mon Jun 11 2018 01:51:57 GMT+0000 (UTC), requestId=1
2018-06-11T01:51:57.821Z - debug: Replaced images [] requestId=1
2018-06-11T01:51:57.822Z - debug: Executing recipe phantom-pdf requestId=1
2018-06-11T01:51:58.003Z - debug: Converting in dedicated phantomjs 1.9.8 timestamp=Mon Jun 11 2018 01:51:57 GMT+0000 (UTC), requestId=1
2018-06-11T01:51:58.004Z - debug: Request file:///%2Ftmp%2Fjsreport%2F065ebf10-6d1a-11e8-a769-3526c68bf69ehtml.html timestamp=Mon Jun 11 2018 01:51:57 GMT+0000 (UTC), requestId=1
2018-06-11T01:51:58.007Z - debug: phantom-pdf recipe finished with 1 pages generated requestId=1
2018-06-11T01:51:58.009Z - debug: Skipping storing report. requestId=1
2018-06-11T01:51:58.016Z - info: Rendering request 1 finished in 233 ms requestId=1
rendering has finished successfully and saved in: /tmp/jsreport/dotnet/binary-default-linux-1.10.0.0/out.pdf

with --keepAlive

root@74033afffebd:/tmp/jsreport/dotnet/binary-default-linux-1.10.0.0# ./jsreport.exe  render --template.engine=none --template.recipe=phantom-pdf --template.content=test.html --out=out.pdf --verbose --keepAlive
looking for previously daemonized instance in: /tmp/jsreport/cli/sock/workerSock cwd: /tmp/jsreport/dotnet/binary-default-linux-1.10.0.0
there is no previously daemonized instance in: /tmp/jsreport/cli/sock/workerSock cwd: /tmp/jsreport/dotnet/binary-default-linux-1.10.0.0
instance has been daemonized and initialized successfully (pid: 6894)
remote server options:
{ url: 'http://localhost:33989/',
  user: undefined,
  password: undefined }
rendering with options:
{
  "template": {
    "engine": "none",
    "recipe": "phantom-pdf",
    "content": "<h1>Hello World</h1>\n"
  }
}
rendering has finished with errors:
Error: An error occurred while trying to execute the command:
    at onCriticalError ([eval]:29603:25)
    at [eval]:29558:13
    at tryCatcher ([eval]:36038:23)
    at Promise._settlePromiseFromHandler ([eval]:34061:31)
    at Promise._settlePromise ([eval]:34118:18)
    at Promise._settlePromise0 ([eval]:34163:10)
    at Promise._settlePromises ([eval]:34238:18)
    at Async._drainQueue ([eval]:31008:16)
    at Async._drainQueues ([eval]:31018:10)
    at Immediate.Async.drainQueues [as _onImmediate] ([eval]:30892:14)
    at processImmediate [as _immediateCallback] (timers.js:396:17) {"originalError":{"code":"ECONNRESET"}}
(Original) Error: socket hang up
    at createHangUpError (_http_client.js:213:15)
    at Socket.socketOnEnd (_http_client.js:305:23)
    at emitNone (events.js:72:20)
    at Socket.emit (events.js:166:7)
    at endReadableNT (_stream_readable.js:923:12)
    at nextTickCallbackWith2Args (node.js:464:9)
    at process._tickCallback (node.js:378:17) {"code":"ECONNRESET"}

[pofider]

@tskimmett Thank you for details. I will try today in my docker and ask for more details if needed.

[tskimmett]

@pofider Alright, thanks a lot. I will also do some more testing on my end to try and emulate exactly what AWS is doing to run my container, as that seems to be the only possible difference.

[pofider]

I've tried on the local docker and it works fine for me. What AWS service you use? Maybe it blocks the local web server or socket.

Can you try to run this in container?

wget -qO- http://localhost:XXXX/api/ping

You can find port in the verbose command output

nstance has been daemonized and initialized successfully (pid: 6894)
remote server options:
{ url: 'http://localhost:33989/',
  user: undefined,
  password: undefined }
rendering with options:

[tskimmett]

I’ll give that a try. I’m using elastic beanstalk to deploy the application, so the container is running on an Amazon Linux EC2 instance.

[pofider]

Hm. Yes that should work fine. Strange. Maybe it is because of the base image.

[tskimmett]

What base image are you using? I’m using microsoft/dotnet:2.1-aspnetcore-runtime.

[pofider]

I meant the image which runs the docker engine runtime. I guess an amazon linux. Btw tried this on my local docker and it works

docker run -it microsoft/dotnet:2.1-aspnetcore-runtime /bin/bash
apt-get update
apt-get install -y libfontconfig1
echo "foo" > test.html
... download or cp jsreport executable
./jsreport  render --keepAlive --template.engine=none --template.recipe=phantom-pdf --template.content=test.html --out=out.pdf --verbose

[tskimmett]

Yes I agree it must be some environmental issue, but that seems counter intuitive since the container should not be affected by the hosting environment.

I will update you when I can check the ping response.

[pofider]

Maybe also good idea to try it on the raw EC2. We don't know what elastic beanstalk configures on the docker runtime. Just to isolate the problem.

We personally rejected using elastic beanstalk and use raw EC2 with docker and cloudformation instead. (Just saying, no recommendation)

[tskimmett]

So I did some more testing on the docker container running in EC2. I downloaded the jsreport binary and ran it as seen below, then tried to perform a render using this server I just created (from a separate console session). You can see the actual error being thrown on the server's end below.

root@e97f6da50ac5:~# ./jsreport start
2018-06-13T02:26:41.843Z - info: Initializing jsreport@1.10.0 in development mode using configuration file: none
2018-06-13T02:26:41.849Z - info: Using extension import-export
2018-06-13T02:26:41.851Z - info: Using extension templates
2018-06-13T02:26:41.853Z - info: Using extension jsrender
2018-06-13T02:26:41.853Z - info: Using extension authentication
2018-06-13T02:26:41.854Z - debug: Extension authentication was disabled
2018-06-13T02:26:41.854Z - info: Using extension cli
2018-06-13T02:26:41.854Z - info: Using extension handlebars
2018-06-13T02:26:41.855Z - info: Using extension debug
2018-06-13T02:26:41.856Z - info: Using extension express
2018-06-13T02:26:41.871Z - info: Using extension fop-pdf
2018-06-13T02:26:41.871Z - info: Using extension tags
2018-06-13T02:26:41.872Z - info: Using extension phantom-pdf
2018-06-13T02:26:41.874Z - info: Using extension fs-store
2018-06-13T02:26:41.875Z - debug: Extension fs-store was disabled
2018-06-13T02:26:41.875Z - info: Using extension authorization
2018-06-13T02:26:41.875Z - debug: Extension authorization was disabled
2018-06-13T02:26:41.875Z - info: Using extension images
2018-06-13T02:26:41.877Z - info: Using extension child-templates
2018-06-13T02:26:41.877Z - info: Using extension browser-client
2018-06-13T02:26:41.878Z - info: Using extension licensing
2018-06-13T02:26:41.878Z - info: Using extension data
2018-06-13T02:26:41.879Z - info: Using extension text
2018-06-13T02:26:41.880Z - info: Using extension reports
2018-06-13T02:26:41.881Z - info: Using extension resources
2018-06-13T02:26:41.882Z - info: Using extension base
2018-06-13T02:26:41.882Z - info: Using extension studio
2018-06-13T02:26:41.883Z - info: Using extension html-to-xlsx
2018-06-13T02:26:41.885Z - info: Using extension scripts
2018-06-13T02:26:41.886Z - info: Using extension assets
2018-06-13T02:26:41.887Z - info: Using extension scheduling
2018-06-13T02:26:41.888Z - info: Using extension xlsx
2018-06-13T02:26:41.889Z - info: Using extension sample-template
2018-06-13T02:26:41.889Z - debug: Creating samples is disabled
2018-06-13T02:26:41.889Z - info: Using extension public-templates
2018-06-13T02:26:41.890Z - debug: Extension public-templates was disabled
2018-06-13T02:26:41.909Z - info: Creating memory store
2018-06-13T02:26:41.937Z - info: Creating default express app.
2018-06-13T02:26:41.978Z - info: jsreport server successfully started on http port: 44865
2018-06-13T02:26:41.979Z - info: Verifying license key free
2018-06-13T02:26:41.980Z - info: Using free license
2018-06-13T02:26:41.983Z - info: reporter initialized
2018-06-13T02:28:07.636Z - info: Starting rendering request 1 (user: null) requestId=1
2018-06-13T02:28:07.638Z - info: Rendering anonymous template { recipe:phantom-pdf,engine:none} requestId=1
2018-06-13T02:28:07.639Z - debug: Data item not defined for this template. requestId=1
2018-06-13T02:28:07.644Z - debug: Resources not defined for this template. requestId=1
2018-06-13T02:28:07.646Z - debug: Base url not specified, skipping its injection. requestId=1
2018-06-13T02:28:07.647Z - debug: Rendering engine none requestId=1
2018-06-13T02:28:07.677Z - debug: Compiled template not found in the cache, compiling timestamp=Wed Jun 13 2018 02:28:07 GMT+0000 (UTC), requestId=1
2018-06-13T02:28:07.681Z - debug: Replaced images [] requestId=1
2018-06-13T02:28:07.683Z - debug: Executing recipe phantom-pdf requestId=1
internal/child_process.js:309
    throw errnoException(err, 'spawn');
    ^

Error: spawn ENOMEM
    at exports._errnoException (util.js:907:11)
    at ChildProcess.spawn (internal/child_process.js:309:11)
    at exports.spawn (child_process.js:363:9)
    at Object.exports.execFile (child_process.js:152:15)
    at jsreportRuntime.js:219949:34
    at jsreportRuntime.js:94025:10
    at [eval]:13339:10
    at FSReqWrap.oncomplete (fs.js:82:15)

So it looks to be some kind of memory issue? I'm not really familiar with how jsreport executes the render procedure, but I guess there isn't enough memory to spawn the process the executes the render?

[tskimmett]

I was able to prevent the error by adding a swap file to my EC2 instance (t2 micro, 1GiB RAM).

All this being said, would you recommend running jsreport on it's own instance to prevent utilizing resources of my aspnet server(s)?