pagedjs works intermittently
We're having strange behavior with dockerized PagedJS in Kotahi. We've now witnessed this on three separate machines (two local instances, one the Kotahi dev machine); though the behavior is intermittent, and difficult to replicate. Basically: sometimes it will generate a PDF, sometimes it won't; with exactly the same file, you get the same results.
From logging, the files are getting into the Docker container and working correctly up to https://gitlab.coko.foundation/cokoapps/pagedjs/-/blob/master/server/api/pagedjs.controller.js#L90 , where the HTML is fed to pagedjs-cli. Sometimes it returns from there; sometimes it doesn't.
We're getting the same results from inside Kotahi and from posting to localhost:3003/api/htmlToPDF. Sometimes it will complete and we'll get a PDF; about two-thirds of the time, we get a timeout, and nothing is returned. Alex put up a demo instance of the dockerized PagesJS at https://pagedjstest.cloud68.co/api/; this works much more reliably.
Attached is a ZIP file that's pretty similar to what we're using – as of right now, we're using base-64 images (though the end of them is in site). This goes through pagedjstest without any trouble; it's gone through my local machine a number of times. Sometimes it hangs though.
Vignesh suggested using the getPreviewerLink API, which is actually really interesting. The first time we tried this and opened the resulting HTML file in a browser, it appeared to loop: the content up to (but not including) the first image was displayed, then repeated seemingly hundreds of times. The next time it worked normally.
One more data point: at one point I got an error returned from inside of pagedjs-cli:
kotahi-server-1 | 2714e77ddd9b23486cd05edf43716cbf_ff2116f1-3a21-43f1-be78-81faaa7dbb5b
kotahi-server-1 | uploads/2714e77ddd9b23486cd05edf43716cbf_ff2116f1-3a21-43f1-be78-81faaa7dbb5b.pdf
kotahi-pagedjs-1 | info: unzipping file in temp/7e73f76341903db5007b8ce80de2b7c6
kotahi-pagedjs-1 | info: removing temp/zip-1643721166415.zip
kotahi-pagedjs-1 | info: creating pdf
kotahi-pagedjs-1 | (node:1) UnhandledPromiseRejectionWarning: Error: Error: Command failed: /home/node/pagedjs/node_modules/.bin/pagedjs-cli -i temp/7e73f76341903db5007b8ce80de2b7c6/index.html -o temp/7e73f76341903db5007b8ce80de2b7c6/output.pdf
kotahi-pagedjs-1 | - Loading: temp/7e73f76341903db5007b8ce80de2b7c6/index.html
kotahi-pagedjs-1 | TimeoutError: Timed out after 30000 ms while trying to connect to the browser! Only Chrome at revision r901912 is guaranteed to work.
kotahi-pagedjs-1 | at Timeout.onTimeout (/home/node/pagedjs/node_modules/puppeteer/lib/cjs/puppeteer/node/BrowserRunner.js:208:20)
kotahi-pagedjs-1 | at listOnTimeout (internal/timers.js:554:17)
kotahi-pagedjs-1 | at processTimers (internal/timers.js:497:7)
kotahi-pagedjs-1 |
kotahi-pagedjs-1 | at conversionHandler (/home/node/pagedjs/server/api/pagedjs.controller.js:131:11)
kotahi-pagedjs-1 | (node:1) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1)
kotahi-pagedjs-1 | (node:1) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
kotahi-server-1 | info: ::ffff:172.19.0.8 - - [01/Feb/2022:13:14:39 +0000] "POST /graphql HTTP/1.1" - - "http://localhost:4000/kotahi/versions/ff2116f1-3a21-43f1-be78-81faaa7dbb5b/production" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36"
kotahi-server-1 |
kotahi-pagedjs-1 | info: ::ffff:172.19.0.6 - - [01/Feb/2022:13:14:46 +0000] "POST /api/htmlToPDF HTTP/1.1" - - "-" "axios/0.21.1"
kotahi-pagedjs-1 |
kotahi-server-1 | error: Request failed with message: ECONNRESET message=Request failed with message: ECONNRESET, locations=[line=2, column=3], path=[convertToPdf], code=INTERNAL_SERVER_ERROR, stacktrace=[Error: Request failed with message: ECONNRESET, at /home/node/app/server/pdfexport/graphql.js:185:25, at processTicksAndRejections (internal/process/task_queues.js:97:5)] The important part of that is this:
TimeoutError: Timed out after 30000 ms while trying to connect to the browser! Only Chrome at revision r901912 is guaranteed to work.though I will note that I have only seen that error once; most of the time it silently times out.
Alex points out this comment at the Puppeteer Github page which is a response to the same error message which seems like it might be connected:
You're running in a very tight environment with a lot of concurrent tasks. In this environment, chrome naturally takes long time to start, thus causing the timeout. You can try increasing the timeout.That feels like it might be describing what's happening: Chrome's taking a very long time to start up inside of Puppeteer, sometimes taking long enough that it just doesn't get it. Is there a way to give it more juice?