Hi,
We use docx quite a lot of docx templates which need to be converted to PDF, so we use the unoconv with pdf
format for this.
Recently I discovered a problem when generating multiple reports of the same request simultaneously. We have some async code which generates 1-10 simulateneous requests for the same template.
Below are the logs of such a scenario, in this case we made 7 simultaneous reqeusts:
2023-10-31T15:07:39.398Z - info: Render request 33 queued for execution and waiting for available worker rootId=6f0hkmepfq04xet, id=6f0hkmepfq04xet
2023-10-31T15:07:39.399Z - warn: Failed persist profile Cannot read properties of undefined (reading 'toString') stack=TypeError: Cannot read properties of undefined (reading 'toString')
at AsyncFunction.<anonymous> (/app/node_modules/@jsreport/jsreport-authorization/lib/modificationListeners.js:33:90)
at ListenerCollection.fire (/app/node_modules/@jsreport/jsreport-core/lib/shared/listenerCollection.js:157:32)
at async Object.insert (/app/node_modules/@jsreport/jsreport-core/lib/main/store/collection.js:141:5)
at async /app/node_modules/@jsreport/jsreport-core/lib/main/profiler.js:184:7
at async /app/node_modules/@jsreport/jsreport-core/lib/main/profiler.js:63:11
2023-10-31T15:07:39.400Z - info: Render request 34 queued for execution and waiting for available worker rootId=olpqs2f2xpb47b4, id=olpqs2f2xpb47b4
2023-10-31T15:07:39.401Z - warn: Failed persist profile Cannot read properties of undefined (reading 'toString') stack=TypeError: Cannot read properties of undefined (reading 'toString')
at AsyncFunction.<anonymous> (/app/node_modules/@jsreport/jsreport-authorization/lib/modificationListeners.js:33:90)
at ListenerCollection.fire (/app/node_modules/@jsreport/jsreport-core/lib/shared/listenerCollection.js:157:32)
at async Object.insert (/app/node_modules/@jsreport/jsreport-core/lib/main/store/collection.js:141:5)
at async /app/node_modules/@jsreport/jsreport-core/lib/main/profiler.js:184:7
at async /app/node_modules/@jsreport/jsreport-core/lib/main/profiler.js:63:11
2023-10-31T15:07:39.401Z - info: Render request 35 queued for execution and waiting for available worker rootId=l9cw7wdxg52lhi4, id=l9cw7wdxg52lhi4
2023-10-31T15:07:39.402Z - warn: Failed persist profile Cannot read properties of undefined (reading 'toString') stack=TypeError: Cannot read properties of undefined (reading 'toString')
at AsyncFunction.<anonymous> (/app/node_modules/@jsreport/jsreport-authorization/lib/modificationListeners.js:33:90)
at ListenerCollection.fire (/app/node_modules/@jsreport/jsreport-core/lib/shared/listenerCollection.js:157:32)
at async Object.insert (/app/node_modules/@jsreport/jsreport-core/lib/main/store/collection.js:141:5)
at async /app/node_modules/@jsreport/jsreport-core/lib/main/profiler.js:184:7
at async /app/node_modules/@jsreport/jsreport-core/lib/main/profiler.js:63:11
2023-10-31T15:07:39.430Z - info: Render request 36 queued for execution and waiting for available worker rootId=jsulq82hmxkm2ak, id=jsulq82hmxkm2ak
2023-10-31T15:07:39.432Z - warn: Failed persist profile Cannot read properties of undefined (reading 'toString') stack=TypeError: Cannot read properties of undefined (reading 'toString')
at AsyncFunction.<anonymous> (/app/node_modules/@jsreport/jsreport-authorization/lib/modificationListeners.js:33:90)
at ListenerCollection.fire (/app/node_modules/@jsreport/jsreport-core/lib/shared/listenerCollection.js:157:32)
at async Object.insert (/app/node_modules/@jsreport/jsreport-core/lib/main/store/collection.js:141:5)
at async /app/node_modules/@jsreport/jsreport-core/lib/main/profiler.js:184:7
at async /app/node_modules/@jsreport/jsreport-core/lib/main/profiler.js:63:11
2023-10-31T15:07:39.461Z - info: Starting rendering request 33 (user: :group/Clients/service-account) rootId=6f0hkmepfq04xet, id=6f0hkmepfq04xet
2023-10-31T15:07:39.461Z - info: Rendering template { name: PDF-nl, recipe: docx, engine: handlebars, preview: false } rootId=6f0hkmepfq04xet, id=6f0hkmepfq04xet
2023-10-31T15:07:39.463Z - info: Render request 37 queued for execution and waiting for available worker rootId=zj1tibf8bnv1x46, id=zj1tibf8bnv1x46
2023-10-31T15:07:39.464Z - warn: Failed persist profile Cannot read properties of undefined (reading 'toString') stack=TypeError: Cannot read properties of undefined (reading 'toString')
at AsyncFunction.<anonymous> (/app/node_modules/@jsreport/jsreport-authorization/lib/modificationListeners.js:33:90)
at ListenerCollection.fire (/app/node_modules/@jsreport/jsreport-core/lib/shared/listenerCollection.js:157:32)
at async Object.insert (/app/node_modules/@jsreport/jsreport-core/lib/main/store/collection.js:141:5)
at async /app/node_modules/@jsreport/jsreport-core/lib/main/profiler.js:184:7
at async /app/node_modules/@jsreport/jsreport-core/lib/main/profiler.js:63:11
2023-10-31T15:07:39.465Z - info: Starting rendering request 34 (user: :group/Clients/service-account) rootId=olpqs2f2xpb47b4, id=olpqs2f2xpb47b4
2023-10-31T15:07:39.465Z - info: Rendering template { name: PDF-nl, recipe: docx, engine: handlebars, preview: false } rootId=olpqs2f2xpb47b4, id=olpqs2f2xpb47b4
2023-10-31T15:07:39.465Z - debug: Inline data specified. rootId=olpqs2f2xpb47b4, id=olpqs2f2xpb47b4
2023-10-31T15:07:39.467Z - debug: Base url not specified, skipping its injection. rootId=olpqs2f2xpb47b4, id=olpqs2f2xpb47b4
2023-10-31T15:07:39.467Z - debug: Rendering engine handlebars rootId=olpqs2f2xpb47b4, id=olpqs2f2xpb47b4
2023-10-31T15:07:39.486Z - debug: Token auth in authorization server was validated correctly
2023-10-31T15:07:39.487Z - debug: API logging in user :group/Clients/service-account
2023-10-31T15:07:39.490Z - debug: Token auth in authorization server was validated correctly
2023-10-31T15:07:39.490Z - debug: API logging in user :group/Clients/service-account
2023-10-31T15:07:39.500Z - info: Render request 38 queued for execution and waiting for available worker rootId=tfj1360ad0ufn0c, id=tfj1360ad0ufn0c
2023-10-31T15:07:39.501Z - warn: Failed persist profile Cannot read properties of undefined (reading 'toString') stack=TypeError: Cannot read properties of undefined (reading 'toString')
at AsyncFunction.<anonymous> (/app/node_modules/@jsreport/jsreport-authorization/lib/modificationListeners.js:33:90)
at ListenerCollection.fire (/app/node_modules/@jsreport/jsreport-core/lib/shared/listenerCollection.js:157:32)
at async Object.insert (/app/node_modules/@jsreport/jsreport-core/lib/main/store/collection.js:141:5)
at async /app/node_modules/@jsreport/jsreport-core/lib/main/profiler.js:184:7
at async /app/node_modules/@jsreport/jsreport-core/lib/main/profiler.js:63:11
2023-10-31T15:07:39.502Z - info: Render request 39 queued for execution and waiting for available worker rootId=40awjagj02kfdmn, id=40awjagj02kfdmn
2023-10-31T15:07:39.503Z - warn: Failed persist profile Cannot read properties of undefined (reading 'toString') stack=TypeError: Cannot read properties of undefined (reading 'toString')
at AsyncFunction.<anonymous> (/app/node_modules/@jsreport/jsreport-authorization/lib/modificationListeners.js:33:90)
at ListenerCollection.fire (/app/node_modules/@jsreport/jsreport-core/lib/shared/listenerCollection.js:157:32)
at async Object.insert (/app/node_modules/@jsreport/jsreport-core/lib/main/store/collection.js:141:5)
at async /app/node_modules/@jsreport/jsreport-core/lib/main/profiler.js:184:7
at async /app/node_modules/@jsreport/jsreport-core/lib/main/profiler.js:63:11
2023-10-31T15:07:39.504Z - debug: Inline data specified. rootId=6f0hkmepfq04xet, id=6f0hkmepfq04xet
2023-10-31T15:07:39.504Z - debug: Base url not specified, skipping its injection. rootId=6f0hkmepfq04xet, id=6f0hkmepfq04xet
2023-10-31T15:07:39.505Z - debug: Rendering engine handlebars rootId=6f0hkmepfq04xet, id=6f0hkmepfq04xet
2023-10-31T15:07:39.600Z - debug: Executing recipe docx rootId=olpqs2f2xpb47b4, id=olpqs2f2xpb47b4
2023-10-31T15:07:39.601Z - info: docx generation is starting rootId=olpqs2f2xpb47b4, id=olpqs2f2xpb47b4
2023-10-31T15:07:39.601Z - debug: Starting child request to render docx dynamic parts rootId=olpqs2f2xpb47b4, id=olpqs2f2xpb47b4
2023-10-31T15:07:39.601Z - info: Starting rendering (child) request (user: :group/Clients/service-account) rootId=olpqs2f2xpb47b4, id=t6w36l9pnmhn00p
2023-10-31T15:07:39.602Z - info: Rendering anonymous template { recipe: html, engine: handlebars } rootId=olpqs2f2xpb47b4, id=t6w36l9pnmhn00p
2023-10-31T15:07:39.602Z - debug: Inline data specified. rootId=olpqs2f2xpb47b4, id=t6w36l9pnmhn00p
2023-10-31T15:07:39.608Z - debug: Base url not specified, skipping its injection. rootId=olpqs2f2xpb47b4, id=t6w36l9pnmhn00p
2023-10-31T15:07:39.608Z - debug: Rendering engine handlebars rootId=olpqs2f2xpb47b4, id=t6w36l9pnmhn00p
2023-10-31T15:07:39.629Z - debug: Executing recipe docx rootId=6f0hkmepfq04xet, id=6f0hkmepfq04xet
2023-10-31T15:07:39.630Z - info: docx generation is starting rootId=6f0hkmepfq04xet, id=6f0hkmepfq04xet
2023-10-31T15:07:39.630Z - debug: Starting child request to render docx dynamic parts rootId=6f0hkmepfq04xet, id=6f0hkmepfq04xet
2023-10-31T15:07:39.630Z - info: Starting rendering (child) request (user: :group/Clients/service-account) rootId=6f0hkmepfq04xet, id=uxhchxjryajrqbv
2023-10-31T15:07:39.630Z - info: Rendering anonymous template { recipe: html, engine: handlebars } rootId=6f0hkmepfq04xet, id=uxhchxjryajrqbv
2023-10-31T15:07:39.631Z - debug: Inline data specified. rootId=6f0hkmepfq04xet, id=uxhchxjryajrqbv
2023-10-31T15:07:39.634Z - debug: Base url not specified, skipping its injection. rootId=6f0hkmepfq04xet, id=uxhchxjryajrqbv
2023-10-31T15:07:39.634Z - debug: Rendering engine handlebars rootId=6f0hkmepfq04xet, id=uxhchxjryajrqbv
2023-10-31T15:07:39.692Z - debug: Executing recipe html rootId=olpqs2f2xpb47b4, id=t6w36l9pnmhn00p
2023-10-31T15:07:39.693Z - debug: Skipping storing report. rootId=olpqs2f2xpb47b4, id=t6w36l9pnmhn00p
2023-10-31T15:07:39.693Z - info: Rendering (child) request finished in 237 ms rootId=olpqs2f2xpb47b4, id=t6w36l9pnmhn00p
2023-10-31T15:07:39.735Z - debug: Executing recipe html rootId=6f0hkmepfq04xet, id=uxhchxjryajrqbv
2023-10-31T15:07:39.736Z - debug: Skipping storing report. rootId=6f0hkmepfq04xet, id=uxhchxjryajrqbv
2023-10-31T15:07:39.736Z - info: Rendering (child) request finished in 275 ms rootId=6f0hkmepfq04xet, id=uxhchxjryajrqbv
2023-10-31T15:07:39.794Z - info: docx generation was finished rootId=olpqs2f2xpb47b4, id=olpqs2f2xpb47b4
2023-10-31T15:07:39.795Z - debug: Executing unoconv commmand unoconv -f pdf /tmp/jsreport/autocleanup/61fbe122-0be1-423a-88b1-759582177c31.docx rootId=olpqs2f2xpb47b4, id=olpqs2f2xpb47b4
2023-10-31T15:07:39.833Z - info: docx generation was finished rootId=6f0hkmepfq04xet, id=6f0hkmepfq04xet
2023-10-31T15:07:39.834Z - debug: Executing unoconv commmand unoconv -f pdf /tmp/jsreport/autocleanup/9c1d9407-05c2-456a-9191-54ca7a79f6a6.docx rootId=6f0hkmepfq04xet, id=6f0hkmepfq04xet
2023-10-31T15:07:40.531Z - warn: Error when processing render request 33
(because) error while executing unoconv
(because) command failed: unoconv -f pdf /tmp/jsreport/autocleanup/9c1d9407-05c2-456a-9191-54ca7a79f6a6.docx
Error: Unable to connect or start own listener. Aborting.
Error: Command failed: unoconv -f pdf /tmp/jsreport/autocleanup/9c1d9407-05c2-456a-9191-54ca7a79f6a6.docx
Error: Unable to connect or start own listener. Aborting.
at ChildProcess.exithandler (node:child_process:419:12)
at ChildProcess.emit (node:events:514:28)
at maybeClose (node:internal/child_process:1091:16)
at ChildProcess._handle.onexit (node:internal/child_process:302:5)
wrapped by:
Error: Error while executing unoconv
(because) command failed: unoconv -f pdf /tmp/jsreport/autocleanup/9c1d9407-05c2-456a-9191-54ca7a79f6a6.docx
Error: Unable to connect or start own listener. Aborting.
at module.exports (/app/node_modules/@jsreport/jsreport-core/lib/shared/createError.js:10:13)
at WorkerReporter.createError (/app/node_modules/@jsreport/jsreport-core/lib/shared/reporter.js:49:12)
at AsyncFunction.<anonymous> (/app/node_modules/@jsreport/jsreport-unoconv/lib/worker.js:46:22)
at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
at async ListenerCollection.fire (/app/node_modules/@jsreport/jsreport-core/lib/shared/listenerCollection.js:157:21)
at async afterRender (/app/node_modules/@jsreport/jsreport-core/lib/worker/render/render.js:103:5)
at async WorkerReporter._render (/app/node_modules/@jsreport/jsreport-core/lib/worker/render/render.js:148:7)
at async /app/node_modules/@jsreport/jsreport-core/lib/worker/reporter.js:224:19
at async processAndResponse (/app/node_modules/@jsreport/advanced-workers/lib/workerHandler.js:41:17) rootId=6f0hkmepfq04xet, id=6f0hkmepfq04xet
2023-10-31T15:07:40.531Z - warn: Rendering request 33 finished with error in 1152 ms rootId=6f0hkmepfq04xet, id=6f0hkmepfq04xet
2023-10-31T15:07:40.533Z - warn: Error during processing request at http://localhost:8506/api/report
2023-10-31T15:07:40.576Z - info: Starting rendering request 35 (user: :group/Clients/service-account) rootId=l9cw7wdxg52lhi4, id=l9cw7wdxg52lhi4
2023-10-31T15:07:40.576Z - info: Rendering template { name: PDF-nl, recipe: docx, engine: handlebars, preview: false } rootId=l9cw7wdxg52lhi4, id=l9cw7wdxg52lhi4
2023-10-31T15:07:40.576Z - debug: Inline data specified. rootId=l9cw7wdxg52lhi4, id=l9cw7wdxg52lhi4
2023-10-31T15:07:40.576Z - debug: Base url not specified, skipping its injection. rootId=l9cw7wdxg52lhi4, id=l9cw7wdxg52lhi4
2023-10-31T15:07:40.577Z - debug: Rendering engine handlebars rootId=l9cw7wdxg52lhi4, id=l9cw7wdxg52lhi4
2023-10-31T15:07:40.684Z - debug: Executing recipe docx rootId=l9cw7wdxg52lhi4, id=l9cw7wdxg52lhi4
2023-10-31T15:07:40.684Z - info: docx generation is starting rootId=l9cw7wdxg52lhi4, id=l9cw7wdxg52lhi4
2023-10-31T15:07:40.685Z - debug: Starting child request to render docx dynamic parts rootId=l9cw7wdxg52lhi4, id=l9cw7wdxg52lhi4
2023-10-31T15:07:40.685Z - info: Starting rendering (child) request (user: :group/Clients/service-account) rootId=l9cw7wdxg52lhi4, id=blyn2avor7iuqr3
2023-10-31T15:07:40.685Z - info: Rendering anonymous template { recipe: html, engine: handlebars } rootId=l9cw7wdxg52lhi4, id=blyn2avor7iuqr3
2023-10-31T15:07:40.685Z - debug: Inline data specified. rootId=l9cw7wdxg52lhi4, id=blyn2avor7iuqr3
2023-10-31T15:07:40.688Z - debug: Base url not specified, skipping its injection. rootId=l9cw7wdxg52lhi4, id=blyn2avor7iuqr3
2023-10-31T15:07:40.688Z - debug: Rendering engine handlebars rootId=l9cw7wdxg52lhi4, id=blyn2avor7iuqr3
2023-10-31T15:07:40.809Z - debug: Executing recipe html rootId=l9cw7wdxg52lhi4, id=blyn2avor7iuqr3
2023-10-31T15:07:40.810Z - debug: Skipping storing report. rootId=l9cw7wdxg52lhi4, id=blyn2avor7iuqr3
2023-10-31T15:07:40.810Z - info: Rendering (child) request finished in 1311 ms rootId=l9cw7wdxg52lhi4, id=blyn2avor7iuqr3
2023-10-31T15:07:40.811Z - info: docx generation was finished rootId=l9cw7wdxg52lhi4, id=l9cw7wdxg52lhi4
2023-10-31T15:07:40.811Z - debug: Executing unoconv commmand unoconv -f pdf /tmp/jsreport/autocleanup/0c6c5fe3-2dd0-41d8-a086-85b540c12abf.docx rootId=l9cw7wdxg52lhi4, id=l9cw7wdxg52lhi4
2023-10-31T15:07:40.929Z - debug: Skipping storing report. rootId=olpqs2f2xpb47b4, id=olpqs2f2xpb47b4
2023-10-31T15:07:40.929Z - info: Rendering request 34 finished in 1543 ms rootId=olpqs2f2xpb47b4, id=olpqs2f2xpb47b4
2023-10-31T15:07:40.971Z - info: Starting rendering request 36 (user: :group/Clients/service-account) rootId=jsulq82hmxkm2ak, id=jsulq82hmxkm2ak
2023-10-31T15:07:40.972Z - info: Rendering template { name: PDF-nl, recipe: docx, engine: handlebars, preview: false } rootId=jsulq82hmxkm2ak, id=jsulq82hmxkm2ak
2023-10-31T15:07:40.972Z - debug: Inline data specified. rootId=jsulq82hmxkm2ak, id=jsulq82hmxkm2ak
2023-10-31T15:07:40.972Z - debug: Base url not specified, skipping its injection. rootId=jsulq82hmxkm2ak, id=jsulq82hmxkm2ak
2023-10-31T15:07:40.972Z - debug: Rendering engine handlebars rootId=jsulq82hmxkm2ak, id=jsulq82hmxkm2ak
2023-10-31T15:07:40.995Z - debug: Executing recipe docx rootId=jsulq82hmxkm2ak, id=jsulq82hmxkm2ak
2023-10-31T15:07:40.996Z - info: docx generation is starting rootId=jsulq82hmxkm2ak, id=jsulq82hmxkm2ak
2023-10-31T15:07:41.067Z - debug: Starting child request to render docx dynamic parts rootId=jsulq82hmxkm2ak, id=jsulq82hmxkm2ak
2023-10-31T15:07:41.067Z - info: Starting rendering (child) request (user: :group/Clients/service-account) rootId=jsulq82hmxkm2ak, id=vjelvi6d85dkqgm
2023-10-31T15:07:41.067Z - info: Rendering anonymous template { recipe: html, engine: handlebars } rootId=jsulq82hmxkm2ak, id=vjelvi6d85dkqgm
2023-10-31T15:07:41.067Z - debug: Inline data specified. rootId=jsulq82hmxkm2ak, id=vjelvi6d85dkqgm
2023-10-31T15:07:41.067Z - debug: Base url not specified, skipping its injection. rootId=jsulq82hmxkm2ak, id=vjelvi6d85dkqgm
2023-10-31T15:07:41.069Z - debug: Rendering engine handlebars rootId=jsulq82hmxkm2ak, id=vjelvi6d85dkqgm
2023-10-31T15:07:41.121Z - debug: Executing recipe html rootId=jsulq82hmxkm2ak, id=vjelvi6d85dkqgm
2023-10-31T15:07:41.121Z - debug: Skipping storing report. rootId=jsulq82hmxkm2ak, id=vjelvi6d85dkqgm
2023-10-31T15:07:41.121Z - info: Rendering (child) request finished in 1659 ms rootId=jsulq82hmxkm2ak, id=vjelvi6d85dkqgm
2023-10-31T15:07:41.222Z - info: docx generation was finished rootId=jsulq82hmxkm2ak, id=jsulq82hmxkm2ak
2023-10-31T15:07:41.223Z - debug: Executing unoconv commmand unoconv -f pdf /tmp/jsreport/autocleanup/38800ad4-3ed6-445b-ac66-42bac514014f.docx rootId=jsulq82hmxkm2ak, id=jsulq82hmxkm2ak
2023-10-31T15:07:41.589Z - debug: Skipping storing report. rootId=jsulq82hmxkm2ak, id=jsulq82hmxkm2ak
2023-10-31T15:07:41.590Z - info: Rendering request 36 finished in 2163 ms rootId=jsulq82hmxkm2ak, id=jsulq82hmxkm2ak
2023-10-31T15:07:41.624Z - info: Starting rendering request 37 (user: :group/Clients/service-account) rootId=zj1tibf8bnv1x46, id=zj1tibf8bnv1x46
2023-10-31T15:07:41.625Z - info: Rendering template { name: PDF-nl, recipe: docx, engine: handlebars, preview: false } rootId=zj1tibf8bnv1x46, id=zj1tibf8bnv1x46
2023-10-31T15:07:41.625Z - debug: Inline data specified. rootId=zj1tibf8bnv1x46, id=zj1tibf8bnv1x46
2023-10-31T15:07:41.643Z - debug: Base url not specified, skipping its injection. rootId=zj1tibf8bnv1x46, id=zj1tibf8bnv1x46
2023-10-31T15:07:41.644Z - debug: Rendering engine handlebars rootId=zj1tibf8bnv1x46, id=zj1tibf8bnv1x46
2023-10-31T15:07:41.750Z - debug: Executing recipe docx rootId=zj1tibf8bnv1x46, id=zj1tibf8bnv1x46
2023-10-31T15:07:41.750Z - info: docx generation is starting rootId=zj1tibf8bnv1x46, id=zj1tibf8bnv1x46
2023-10-31T15:07:41.750Z - debug: Starting child request to render docx dynamic parts rootId=zj1tibf8bnv1x46, id=zj1tibf8bnv1x46
2023-10-31T15:07:41.750Z - info: Starting rendering (child) request (user: :group/Clients/service-account) rootId=zj1tibf8bnv1x46, id=amjvycqs5tddz23
2023-10-31T15:07:41.750Z - info: Rendering anonymous template { recipe: html, engine: handlebars } rootId=zj1tibf8bnv1x46, id=amjvycqs5tddz23
2023-10-31T15:07:41.751Z - debug: Inline data specified. rootId=zj1tibf8bnv1x46, id=amjvycqs5tddz23
2023-10-31T15:07:41.754Z - debug: Base url not specified, skipping its injection. rootId=zj1tibf8bnv1x46, id=amjvycqs5tddz23
2023-10-31T15:07:41.754Z - debug: Rendering engine handlebars rootId=zj1tibf8bnv1x46, id=amjvycqs5tddz23
2023-10-31T15:07:41.869Z - debug: Skipping storing report. rootId=l9cw7wdxg52lhi4, id=l9cw7wdxg52lhi4
2023-10-31T15:07:41.869Z - info: Rendering request 35 finished in 2476 ms rootId=l9cw7wdxg52lhi4, id=l9cw7wdxg52lhi4
2023-10-31T15:07:41.876Z - debug: Executing recipe html rootId=zj1tibf8bnv1x46, id=amjvycqs5tddz23
2023-10-31T15:07:41.876Z - debug: Skipping storing report. rootId=zj1tibf8bnv1x46, id=amjvycqs5tddz23
2023-10-31T15:07:41.876Z - info: Rendering (child) request finished in 2310 ms rootId=zj1tibf8bnv1x46, id=amjvycqs5tddz23
2023-10-31T15:07:41.876Z - info: docx generation was finished rootId=zj1tibf8bnv1x46, id=zj1tibf8bnv1x46
2023-10-31T15:07:41.876Z - debug: Executing unoconv commmand unoconv -f pdf /tmp/jsreport/autocleanup/fcf591c8-3b18-4669-9408-6209a86bed61.docx rootId=zj1tibf8bnv1x46, id=zj1tibf8bnv1x46
2023-10-31T15:07:41.912Z - info: Starting rendering request 38 (user: :group/Clients/service-account) rootId=tfj1360ad0ufn0c, id=tfj1360ad0ufn0c
2023-10-31T15:07:41.913Z - info: Rendering template { name: PDF-nl, recipe: docx, engine: handlebars, preview: false } rootId=tfj1360ad0ufn0c, id=tfj1360ad0ufn0c
2023-10-31T15:07:41.914Z - debug: Inline data specified. rootId=tfj1360ad0ufn0c, id=tfj1360ad0ufn0c
2023-10-31T15:07:41.919Z - debug: Base url not specified, skipping its injection. rootId=tfj1360ad0ufn0c, id=tfj1360ad0ufn0c
2023-10-31T15:07:41.919Z - debug: Rendering engine handlebars rootId=tfj1360ad0ufn0c, id=tfj1360ad0ufn0c
2023-10-31T15:07:42.007Z - debug: Executing recipe docx rootId=tfj1360ad0ufn0c, id=tfj1360ad0ufn0c
2023-10-31T15:07:42.007Z - info: docx generation is starting rootId=tfj1360ad0ufn0c, id=tfj1360ad0ufn0c
2023-10-31T15:07:42.007Z - debug: Starting child request to render docx dynamic parts rootId=tfj1360ad0ufn0c, id=tfj1360ad0ufn0c
2023-10-31T15:07:42.007Z - info: Starting rendering (child) request (user: :group/Clients/service-account) rootId=tfj1360ad0ufn0c, id=ctfh53ftfqbcfi5
2023-10-31T15:07:42.008Z - info: Rendering anonymous template { recipe: html, engine: handlebars } rootId=tfj1360ad0ufn0c, id=ctfh53ftfqbcfi5
2023-10-31T15:07:42.008Z - debug: Inline data specified. rootId=tfj1360ad0ufn0c, id=ctfh53ftfqbcfi5
2023-10-31T15:07:42.008Z - debug: Base url not specified, skipping its injection. rootId=tfj1360ad0ufn0c, id=ctfh53ftfqbcfi5
2023-10-31T15:07:42.008Z - debug: Rendering engine handlebars rootId=tfj1360ad0ufn0c, id=ctfh53ftfqbcfi5
2023-10-31T15:07:42.121Z - debug: Executing recipe html rootId=tfj1360ad0ufn0c, id=ctfh53ftfqbcfi5
2023-10-31T15:07:42.122Z - debug: Skipping storing report. rootId=tfj1360ad0ufn0c, id=ctfh53ftfqbcfi5
2023-10-31T15:07:42.122Z - info: Rendering (child) request finished in 2535 ms rootId=tfj1360ad0ufn0c, id=ctfh53ftfqbcfi5
2023-10-31T15:07:42.122Z - info: docx generation was finished rootId=tfj1360ad0ufn0c, id=tfj1360ad0ufn0c
2023-10-31T15:07:42.122Z - debug: Executing unoconv commmand unoconv -f pdf /tmp/jsreport/autocleanup/515d6fb0-60bd-48ef-b2a1-d3c31fa77fe0.docx rootId=tfj1360ad0ufn0c, id=tfj1360ad0ufn0c
2023-10-31T15:07:42.487Z - debug: Skipping storing report. rootId=tfj1360ad0ufn0c, id=tfj1360ad0ufn0c
2023-10-31T15:07:42.487Z - info: Rendering request 38 finished in 2999 ms rootId=tfj1360ad0ufn0c, id=tfj1360ad0ufn0c
2023-10-31T15:07:42.520Z - info: Starting rendering request 39 (user: :group/Clients/service-account) rootId=40awjagj02kfdmn, id=40awjagj02kfdmn
2023-10-31T15:07:42.520Z - info: Rendering template { name: PDF-nl, recipe: docx, engine: handlebars, preview: false } rootId=40awjagj02kfdmn, id=40awjagj02kfdmn
2023-10-31T15:07:42.520Z - debug: Inline data specified. rootId=40awjagj02kfdmn, id=40awjagj02kfdmn
2023-10-31T15:07:42.520Z - debug: Base url not specified, skipping its injection. rootId=40awjagj02kfdmn, id=40awjagj02kfdmn
2023-10-31T15:07:42.520Z - debug: Rendering engine handlebars rootId=40awjagj02kfdmn, id=40awjagj02kfdmn
2023-10-31T15:07:42.622Z - debug: Executing recipe docx rootId=40awjagj02kfdmn, id=40awjagj02kfdmn
2023-10-31T15:07:42.623Z - info: docx generation is starting rootId=40awjagj02kfdmn, id=40awjagj02kfdmn
2023-10-31T15:07:42.623Z - debug: Starting child request to render docx dynamic parts rootId=40awjagj02kfdmn, id=40awjagj02kfdmn
2023-10-31T15:07:42.623Z - info: Starting rendering (child) request (user: :group/Clients/service-account) rootId=40awjagj02kfdmn, id=kew5i5egdruzv8f
2023-10-31T15:07:42.623Z - info: Rendering anonymous template { recipe: html, engine: handlebars } rootId=40awjagj02kfdmn, id=kew5i5egdruzv8f
2023-10-31T15:07:42.623Z - debug: Inline data specified. rootId=40awjagj02kfdmn, id=kew5i5egdruzv8f
2023-10-31T15:07:42.623Z - debug: Base url not specified, skipping its injection. rootId=40awjagj02kfdmn, id=kew5i5egdruzv8f
2023-10-31T15:07:42.624Z - debug: Rendering engine handlebars rootId=40awjagj02kfdmn, id=kew5i5egdruzv8f
2023-10-31T15:07:42.733Z - debug: Executing recipe html rootId=40awjagj02kfdmn, id=kew5i5egdruzv8f
2023-10-31T15:07:42.733Z - debug: Skipping storing report. rootId=40awjagj02kfdmn, id=kew5i5egdruzv8f
2023-10-31T15:07:42.734Z - info: Rendering (child) request finished in 3150 ms rootId=40awjagj02kfdmn, id=kew5i5egdruzv8f
2023-10-31T15:07:42.833Z - info: docx generation was finished rootId=40awjagj02kfdmn, id=40awjagj02kfdmn
2023-10-31T15:07:42.834Z - debug: Executing unoconv commmand unoconv -f pdf /tmp/jsreport/autocleanup/4f207934-98d1-4c59-a30c-8af7267f6b06.docx rootId=40awjagj02kfdmn, id=40awjagj02kfdmn
2023-10-31T15:07:42.883Z - debug: Skipping storing report. rootId=zj1tibf8bnv1x46, id=zj1tibf8bnv1x46
2023-10-31T15:07:42.883Z - info: Rendering request 37 finished in 3426 ms rootId=zj1tibf8bnv1x46, id=zj1tibf8bnv1x46
2023-10-31T15:07:43.833Z - debug: Skipping storing report. rootId=40awjagj02kfdmn, id=40awjagj02kfdmn
2023-10-31T15:07:43.833Z - info: Rendering request 39 finished in 4341 ms rootId=40awjagj02kfdmn, id=40awjagj02kfdmn
Besides some warnings about saving profiles (which don't bother me too much), the following shows the failing request:
2023-10-31T15:07:40.531Z - warn: Error when processing render request 33
(because) error while executing unoconv
(because) command failed: unoconv -f pdf /tmp/jsreport/autocleanup/9c1d9407-05c2-456a-9191-54ca7a79f6a6.docx
Error: Unable to connect or start own listener. Aborting.
Error: Command failed: unoconv -f pdf /tmp/jsreport/autocleanup/9c1d9407-05c2-456a-9191-54ca7a79f6a6.docx
Error: Unable to connect or start own listener. Aborting.
at ChildProcess.exithandler (node:child_process:419:12)
at ChildProcess.emit (node:events:514:28)
at maybeClose (node:internal/child_process:1091:16)
at ChildProcess._handle.onexit (node:internal/child_process:302:5)
wrapped by:
Error: Error while executing unoconv
(because) command failed: unoconv -f pdf /tmp/jsreport/autocleanup/9c1d9407-05c2-456a-9191-54ca7a79f6a6.docx
Error: Unable to connect or start own listener. Aborting.
at module.exports (/app/node_modules/@jsreport/jsreport-core/lib/shared/createError.js:10:13)
at WorkerReporter.createError (/app/node_modules/@jsreport/jsreport-core/lib/shared/reporter.js:49:12)
at AsyncFunction.<anonymous> (/app/node_modules/@jsreport/jsreport-unoconv/lib/worker.js:46:22)
at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
at async ListenerCollection.fire (/app/node_modules/@jsreport/jsreport-core/lib/shared/listenerCollection.js:157:21)
at async afterRender (/app/node_modules/@jsreport/jsreport-core/lib/worker/render/render.js:103:5)
at async WorkerReporter._render (/app/node_modules/@jsreport/jsreport-core/lib/worker/render/render.js:148:7)
at async /app/node_modules/@jsreport/jsreport-core/lib/worker/reporter.js:224:19
at async processAndResponse (/app/node_modules/@jsreport/advanced-workers/lib/workerHandler.js:41:17) rootId=6f0hkmepfq04xet, id=6f0hkmepfq04xet
Is it to be expected that JSReport handles this correctly?
When I disable the 'unoconv' property on this request, everything works fine, but as we need PDF reports that is not really an option.