node-export-server icon indicating copy to clipboard operation
node-export-server copied to clipboard

Export server run issue for multiple request

Open PRABHASITHREDDY opened this issue 1 year ago • 25 comments

Iam running my export server using "highcharts-export-server --enableServer 1 --host localhost --port 3012 --enableServer 1 --minWorkers 4 --maxWorkers 20"

this is working fine when i send 1 request a time but if i send more than 5 requests at a time iam facing errors like

Wed Aug 07 2024 22:06:08 GMT+0530 [error] - [export] Work: 7ac0c690b1554c75adc39d608f565ce3 could not be completed, sending: In pool.postWork: [pool] Error when acquiring available entry: Error: operation timed out for an unknown reason.

Wed Aug 07 2024 22:06:30 GMT+0530 [error] - [export] Work: 6f1192a9522b4b71b627341c7f163bc1 could not be completed, sending: In pool.postWork: Error trying to perform puppeteer export: Error: Requesting main frame too early!.

Can Anyone help me with solving the issue

PRABHASITHREDDY avatar Aug 07 '24 16:08 PRABHASITHREDDY

Thanks for reporting @PRABHASITHREDDY!

We will investigate this issue and if the information that you provided is enough for our local reproduction, we will add it to our backlog. If not, I will ask you for more details.

jszuminski avatar Aug 13 '24 07:08 jszuminski

Hi,

I am facing the same issue. Could something be missing in the configuration?

I've included below that minimum number of workers is set to 8 and max at 48. I am sending 16 requests simultaneously hoping that the other 8 workers will be created but they never get created. You can see that in the log below, 7 workers are waiting to be created but they shouldn't wait. I have set max workers to 48.

Please help me understand the issue and provide any workarounds.

Fri Aug 16 2024 02:38:28 GMT+0000 [verbose] - [pool] Work received, starting to process. Fri Aug 16 2024 02:38:28 GMT+0000 [benchmark] - [pool] The minimum number of resources allowed by pool: 8. Fri Aug 16 2024 02:38:28 GMT+0000 [benchmark] - [pool] The maximum number of resources allowed by pool: 48. Fri Aug 16 2024 02:38:28 GMT+0000 [benchmark] - [pool] The number of all created resources: 8. Fri Aug 16 2024 02:38:28 GMT+0000 [benchmark] - [pool] The number of available resources: 0. Fri Aug 16 2024 02:38:28 GMT+0000 [benchmark] - [pool] The number of acquired resources: 8. Fri Aug 16 2024 02:38:28 GMT+0000 [benchmark] - [pool] The number of resources waiting to be acquired: 7. Fri Aug 16 2024 02:38:28 GMT+0000 [verbose] - [pool] Acquiring a worker handle. Fri Aug 16 2024 02:38:32 GMT+0000 [error] - [pool] In pool.postWork: For request with ID 8f1b64d1b9ef4b37bf7b5342ae6c2146 - Error encountered when acquiring an available entry: 5088.926711ms. Error: operation timed out for an unknown reason at /opt/node-export-server/node_modules/tarn/dist/PendingOperation.js:14:27 at async postWork (file:///opt/node-export-server/lib/pool.js:272:22) at async doExport (file:///opt/node-export-server/lib/chart.js:439:20) at async exportHandler (file:///opt/node-export-server/lib/server/routes/export.js:212:5)

anantjagania avatar Aug 16 '24 02:08 anantjagania

Any news on that @jszuminski ?

I've got the same Problem/Error ...

[error] - [pool] In pool.postWork: For request with ID 592be5b34baa44e3b875ec37ee157c6b - Error encountered when acquiring an available entry: 5000.231517ms. 
Error: operation timed out for an unknown reason
   at /usr/local/lib/node_modules/highcharts-export-server/node_modules/tarn/dist/PendingOperation.js:17:27
   at runNextTicks (node:internal/process/task_queues:60:5)
   at listOnTimeout (node:internal/timers:545:9)
   at process.processTimers (node:internal/timers:519:7)
   at async postWork (file:///usr/local/lib/node_modules/highcharts-export-server/lib/pool.js:272:22)
   at async doExport (file:///usr/local/lib/node_modules/highcharts-export-server/lib/chart.js:448:24)
   at async exportHandler (file:///usr/local/lib/node_modules/highcharts-export-server/lib/server/routes/export.js:212:5)

... using this Docker image in Kubernetes (see version numbers) ...

FROM ghcr.io/puppeteer/puppeteer:23.3.0

ENV NODE_ENV=production
ENV ACCEPT_HIGHCHARTS_LICENSE=YES
ENV HIGHCHARTS_VERSION=9.3.3
ENV PUPPETEER_EXECUTABLE_PATH=/usr/bin/chromium
ENV HIGHCHARTS_CACHE_PATH=/tmp/.cache
ENV LOGGING_LEVEL=3
ENV LOGGING_TO_FILE=false
ENV POOL_MIN_WORKERS=4
ENV POOL_MAX_WORKERS=8
ENV POOL_BENCHMARKING=false
ENV SERVER_BENCHMARKING=false
ENV XDG_CONFIG_HOME=/tmp/.chromium
ENV XDG_CACHE_HOME=/tmp/.chromium

USER root

RUN apt-get update && apt-get install -y chromium

WORKDIR /node-export-server

RUN npm install [email protected] -g

COPY node-export-server-patches/4.0.2/lib/cache.js /usr/local/lib/node_modules/highcharts-export-server/lib/cache.js
COPY node-export-server-patches/4.0.2/lib/chart.js /usr/local/lib/node_modules/highcharts-export-server/lib/chart.js

EXPOSE 7801
ENTRYPOINT ["highcharts-export-server", "--enableServer", "1", "--allowCodeExecution", "true", "--callback", "true"]

It seems that it goes into this state, when there are too many requests that the pool cannot handle anymore (tested with Postman)!? After all connections are closed (by the client after a timeout) it works again.

It must be some change after 11th September 2024, because I tried the same requests on a Pod with an image created before this date without any Problems/Errors !!!

See log file attached, a lot of parallel (automated) requests followed by 4 single (manual) requests (with the same error) and then 2 single (manual) requests that wehre successful! node-export-server-pod.log

baroso avatar Feb 26 '25 15:02 baroso

@jszuminski, I just found the commit that introduced this Problem :)

These changes here https://github.com/highcharts/node-export-server/commit/b9bd1ed83d857baa77e777e6f8b3d26bac9bd4c1 in the pool.js are responsible for the error!

See also the history here https://github.com/highcharts/node-export-server/commits/master/lib/pool.js

It works, when using this version here https://github.com/highcharts/node-export-server/blob/5334f733304bb1547a3bf7ee8585148db5d598b6/lib/pool.js of the pool.js!

Updated Dockerfile ...

FROM ghcr.io/puppeteer/puppeteer:23.3.0

ENV NODE_ENV=production
ENV ACCEPT_HIGHCHARTS_LICENSE=YES
ENV HIGHCHARTS_VERSION=9.3.3
ENV PUPPETEER_EXECUTABLE_PATH=/usr/bin/chromium
ENV HIGHCHARTS_CACHE_PATH=/tmp/.cache
ENV LOGGING_LEVEL=3
ENV LOGGING_TO_FILE=false
ENV POOL_MIN_WORKERS=4
ENV POOL_MAX_WORKERS=8
ENV POOL_BENCHMARKING=false
ENV SERVER_BENCHMARKING=false
ENV XDG_CONFIG_HOME=/tmp/.chromium
ENV XDG_CACHE_HOME=/tmp/.chromium

USER root

RUN apt-get update && apt-get install -y chromium

WORKDIR /node-export-server

RUN npm install [email protected] -g

COPY node-export-server-patches/4.0.2/lib/cache.js /usr/local/lib/node_modules/highcharts-export-server/lib/cache.js
COPY node-export-server-patches/4.0.2/lib/chart.js /usr/local/lib/node_modules/highcharts-export-server/lib/chart.js
COPY node-export-server-patches/4.0.2/lib/pool.js /usr/local/lib/node_modules/highcharts-export-server/lib/pool.js

EXPOSE 7801
ENTRYPOINT ["highcharts-export-server", "--enableServer", "1", "--allowCodeExecution", "true", "--callback", "true"]

baroso avatar Feb 27 '25 16:02 baroso

@jszuminski, sorry, but I celebrated a little bit too early :(

After deploying the above Dockerfile/Image to Kubernetes, I made a stress test with 20 concurrent users over 3 minutes with this JSON ...

{"infile":{"title": {"text": "Steep Chart"}, "xAxis": {"categories": ["Jan", "Feb", "Mar"]}, "series": [{"data": [29.9, 71.5, 106.4]}]}}

Image

You can see that after about 1 minute and 40 seconds I got these errors again, so there ist definitely a big issue with requests from concurrent users!

baroso avatar Feb 27 '25 16:02 baroso

Further tests with Postman

It works with 20 concurrent users over 3 minutes with POOL_MIN_WORKERS=1 & POOL_MAX_WORKERS=1 ...

Image

It DOESNT work with 100 concurrent users over 3 minutes with POOL_MIN_WORKERS=1 & POOL_MAX_WORKERS=1 ...

Image

baroso avatar Mar 18 '25 08:03 baroso

I definitely seems that the problem arises with more concurrent users and it get's worse with more workers!

baroso avatar Mar 18 '25 08:03 baroso

@jszuminski, @cvasseng or @PaulDalek, since you seem to be the main contributors for this project, could you please provide some Feedback to this issue and 2 (maybe) related issues ...

https://github.com/highcharts/node-export-server/issues/619 https://github.com/highcharts/node-export-server/issues/640

baroso avatar Mar 18 '25 08:03 baroso

So sorry for the late reply here, @baroso and others!

Our devs will look at this, and related issues, this week. Will update this thread with new status.

Stian Totland Product Manager, Highsoft

stitot avatar Mar 19 '25 07:03 stitot

@stitot, could you developers find a solution to this issue?

I've tested this issue again using v5.0.0 and different amounts of workers ... unfortunately the same error still occurs ...

Thu Mar 27 2025 10:29:34 GMT+0000 [error] - [pool] In pool.postWork: For request with ID cbb4cba7f9b34ecdbb60aba06e5b7bb5 - Error encountered when acquiring an available entry: 5002.455244ms. 
Error: operation timed out for an unknown reason
   at /usr/local/lib/node_modules/highcharts-export-server/node_modules/tarn/dist/PendingOperation.js:17:27
   at async postWork (file:///usr/local/lib/node_modules/highcharts-export-server/lib/pool.js:293:22)
   at async doExport (file:///usr/local/lib/node_modules/highcharts-export-server/lib/chart.js:448:24)
   at async exportHandler (file:///usr/local/lib/node_modules/highcharts-export-server/lib/server/routes/export.js:225:5)

1st Test with 100 concurrent users over 3 minutes with POOL_MIN_WORKERS=1 & POOL_MAX_WORKERS=2 ...

Image

2nd Test with 100 concurrent users over 3 minutes with POOL_MIN_WORKERS=1 & POOL_MAX_WORKERS=1 ...

Image

3rd Test with 100 concurrent users over 3 minutes with POOL_MIN_WORKERS=4 & POOL_MAX_WORKERS=8 ...

Image

baroso avatar Mar 27 '25 10:03 baroso

Thank you for your feedback, @baroso! Looking into it...

Stian

stitot avatar Mar 27 '25 12:03 stitot

Hi @stitot (Stian), do you have news on this issue?

Our current problem/dilemma is, that we have a running Kubernetes-Production-Pod that we cannot stop/restart because, we have (accidentally) overwritten the working image ... so, we need to wait for the fix, to create another image that is working (doesn't include this error). I also tried to create a new image with an older (working) version, but I wasn't able to create it.

So, this issue is kind of urgent for us :)

baroso avatar Apr 01 '25 08:04 baroso

Hi @stitot (Stian), any news on this issue?

baroso avatar Apr 07 '25 06:04 baroso

Hi @stitot (Stian) or whoever is working on this issue, do you have any status about the progress or an ETA on when we can expect a fix?

As I stated above, this issue is really urgent for us and it would be really great to have a fix soon :)

Kind regards, Robert Baminger

baroso avatar Apr 15 '25 08:04 baroso

@baroso,

so sorry that this has taken so long! This issue is next up in our backlog now, but due to Easter I can't guarantee final fix/feedback this week.

Stian

stitot avatar Apr 15 '25 09:04 stitot

@stitot ... Ok, no problem, thanks for the update and happy easter holidays :)

Robert

baroso avatar Apr 15 '25 11:04 baroso

TGIF ;)

Hi @stitot (Stian), any further news on this issue?

baroso avatar Apr 25 '25 07:04 baroso

Hi @stitot (Stian), slowly we're getting desperate! Do you have any further (good) news on this issue?

baroso avatar May 06 '25 07:05 baroso

Hello @baroso,

So sorry for the late reply. This is a complicated issue. It’s difficult to configure the server to handle a large number of concurrent requests while also maintaining an optimal number of workers. You could try adjusting not only the number of workers but also the timeouts (especially the acquireTimeout, which defaults to 5000 ms) or the work limit per worker (workLimit is set to 40 by default).

There’s also an experimental branch with significant changes you can test to see if it performs better: https://github.com/highcharts/node-export-server/tree/dev/enhanced-sandbox.

PaulDalek avatar May 06 '25 13:05 PaulDalek

@PaulDalek, since im using node-export-server as a Pod in Kubernetes, I can start multiple Pods to balance the load, but even then these errors occur.

It seems to work in v4.0.2, because we still have a Pod running since Nov. 2024 without issues, we never got this particular error there! Although I can't tell for sure, because I've not tested it again, and I don't want to, since this is our (last) production Pod, which we can't afford to mess with or lose!

So yes, I will try to adjust the settings you suggested.

What I didn't accomplish until now is, to write a working Dockerfile that installs node-export-server from source (the branch you suggested to try). Could you please help me to change the following Dockerfile to get it to work ...

FROM ghcr.io/puppeteer/puppeteer:24.4.0

ENV NODE_ENV=production
ENV ACCEPT_HIGHCHARTS_LICENSE=YES
ENV HIGHCHARTS_VERSION=9.3.3
ENV PUPPETEER_EXECUTABLE_PATH=/usr/bin/chromium
ENV HIGHCHARTS_CACHE_PATH=/tmp/.cache
ENV LOGGING_LEVEL=3
ENV LOGGING_TO_FILE=false
ENV POOL_MIN_WORKERS=4
ENV POOL_MAX_WORKERS=8
ENV POOL_BENCHMARKING=false
ENV SERVER_BENCHMARKING=false
ENV XDG_CONFIG_HOME=/tmp/.chromium
ENV XDG_CACHE_HOME=/tmp/.chromium

USER root

RUN apt-get update && apt-get install -y chromium

WORKDIR /node-export-server

RUN npm install [email protected] -g

COPY node-export-server-patches/5.0.0/lib/schemas/config.json /usr/local/lib/node_modules/highcharts-export-server/lib/schemas/config.json

EXPOSE 7801
ENTRYPOINT ["highcharts-export-server", "--enableServer", "1", "--allowCodeExecution", "true", "--callback", "true", "--loadConfig", "/usr/local/lib/node_modules/highcharts-export-server/lib/schemas/config.json"]

baroso avatar May 07 '25 09:05 baroso

@baroso Ok, I see. So v4.0.2 works fine, right? You mentioned a commit (https://github.com/highcharts/node-export-server/commit/b9bd1ed83d857baa77e777e6f8b3d26bac9bd4c1) in this comment: https://github.com/highcharts/node-export-server/issues/568#issuecomment-2688424601, which might be causing the issue. That commit is from November '24, while v4.0.2 is from August '24. Did you create the pod from a specific commit or branch? If so, can you switch to v4.0.2 for now until the issue is resolved?

Regarding the Dockerfile, I’ll take a look and see how I can help.

PaulDalek avatar May 07 '25 09:05 PaulDalek

@PaulDalek, unfortunately I don't remember correctly. I already tried it with v4.0.2 again, but now I'm getting the same error ... it's very confusing, since I tried already so many variations.

If you can provide a working Dockerfile that installs node-export-server from source, I can try more variations and also tune it with the settings you suggested.

Could you reproduce this error on your side or do you have a working version (incl. timeout/limit settings)?

baroso avatar May 07 '25 11:05 baroso

Hi @baroso, we have an "internal" Docker-based branch under https://github.com/highcharts/node-export-server/tree/enhancement/docker also, while this is quite specific to our needs in particular, maybe the Dockerfile there could be some help to you. Note that it requires some changes done in that branch in general, so it won't work on main for instance.

That said, since exports in a general sense seem to work for you (just not under any real load), I'd think that the issue isn't necessarily Docker related (though I suppose it could be related to ulimit or other similar mechanisms in the container, though that would be strange.. especially if your trying the same setup as you have running in production with an earlier version).

Would it be possible for you to share some details on what resources the failing container is running with, so we can try to replicate your setup? Puppeteer is quite hungry for especially RAM, and tight CPU budgets might also cause the kind of behavior you're seeing.

cvasseng avatar May 09 '25 10:05 cvasseng

Hi @cvasseng, @PaulDalek, @stitot & @all, I finally solved all my Problems ... thanks for your help (and sorry it took such a long time) :)

Here is my Dockerfile ...

FROM node:24-slim as base

# Build application
FROM base as build

WORKDIR /node-export-server

RUN apt update -y && \
    apt-get install --no-install-recommends -y ca-certificates git

# Clone and install highcharts node-export-server
RUN git clone https://github.com/highcharts/node-export-server.git . \
    && git checkout refs/tags/5.0.0

RUN npm ci --ignore-scripts
RUN npm install highcharts
RUN npm run build

# Create runtime image with only the necessary files
FROM base as runtime

ENV NODE_ENV=production
ENV ACCEPT_HIGHCHARTS_LICENSE=YES
ENV HIGHCHARTS_VERSION=9.3.3

ENV PUPPETEER_EXECUTABLE_PATH=/usr/bin/chromium
ENV XDG_CONFIG_HOME=/tmp/.chromium
ENV XDG_CACHE_HOME=/tmp/.chromium

RUN apt update -y && \
    apt-get install --no-install-recommends -y chromium chromium-l10n ca-certificates fonts-liberation libappindicator3-1 libasound2 libatk-bridge2.0-0 libatk1.0-0 libc6 libcairo2 libcups2 libdbus-1-3 libexpat1 libfontconfig1 libgbm1 libgcc1 libglib2.0-0 libgtk-3-0 libnspr4 libnss3 libpango-1.0-0 libpangocairo-1.0-0 libstdc++6 libx11-6 libx11-xcb1 libxcb1 libxcomposite1 libxcursor1 libxdamage1 libxext6 libxfixes3 libxi6 libxrandr2 libxrender1 libxss1 libxtst6 lsb-release wget xdg-utils && \
    rm -rf /var/lib/apt/lists/*

WORKDIR /node-export-server

COPY --from=build /node-export-server/package.json /node-export-server/package-lock.json /node-export-server/.puppeteerrc.cjs ./

RUN npm ci --ignore-scripts && \
    npx puppeteer browsers install chrome

COPY --from=build /node-export-server/dist/index.esm.js ./dist/index.esm.js
COPY --from=build /node-export-server/templates ./templates
COPY --from=build /node-export-server/public ./public
COPY --from=build /node-export-server/node_modules/highcharts/*.js ./static/
COPY --from=build /node-export-server/node_modules/highcharts/modules/*.js ./static/modules/
COPY --from=build /node-export-server/node_modules/highcharts/indicators/indicators-all.js ./static/stock/indicators/
COPY --from=build /node-export-server/node_modules/highcharts/modules/map.js ./static/maps/modules/
COPY --from=build /node-export-server/lib ./lib
COPY --from=build /node-export-server/msg ./msg
COPY --from=build /node-export-server/bin/cli.js ./bin/cli.js

COPY node-export-server-patches/5.0.0/lib/cache.js ./lib/cache.js
COPY node-export-server-patches/5.0.0/lib/chart.js ./lib/chart.js
COPY node-export-server-patches/5.0.0/lib/schemas/config.json ./lib/schemas/config.json

EXPOSE 7801
ENTRYPOINT ["node", "/node-export-server/bin/cli.js", "--enableServer", "1", "--allowCodeExecution", "true", "--callback", "true", "--loadConfig", "/node-export-server/lib/schemas/config.json"]

Here's my config file ...

{
  "puppeteer": {
    "args": ["--no-sandbox"]
  },
  "highcharts": {
    "cachePath": "/tmp/.cache"
  },
  "server": {
    "benchmarking": false
  },
  "pool": {
    "minWorkers": 4,
    "maxWorkers": 16,
    "workLimit": 100,
    "acquireTimeout": 30000,
    "benchmarking": false
  },
  "export": {
    "rasterizationTimeout": 60000
  },
  "logging": {
    "level": 3,
    "dest": "",
    "toFile": false
  }
}

@PaulDalek, it worked with the config tweaks you suggested!

1st Test with 100 concurrent users over 3 minutes and 1 Kubernetes Pod ...

Image

2nd Test with 100 concurrent users over 3 minutes and 3 Kubernetes Pods ...

Image

3rd Test with 100 concurrent users over 3 minutes and 6 Kubernetes Pods ...

Image

baroso avatar Jul 10 '25 16:07 baroso

Hi @baroso ,

Great to hear that and thanks for letting us know!

PaulDalek avatar Jul 10 '25 18:07 PaulDalek