# Reporting generation vs timeout

**URL:** <https://discuss.elastic.co/t/reporting-generation-vs-timeout/208853>\
**Category:** Kibana\
**Tags:** elastic-stack-reporting\
**Created:** [November 21, 2019, 10:13am UTC](https://discuss.elastic.co/t/reporting-generation-vs-timeout/208853 "2019-11-21T10:13:55Z")\
**Posts on this page:** 10\
**Page:** 1

<div class="post-metadata">

**Author:** ![stefws](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/stefws/32/6442_2.png) [@stefws](https://discuss.elastic.co/u/stefws)\
**Post date:** [November 21, 2019, 10:13am UTC](https://discuss.elastic.co/t/reporting-generation-vs-timeout/208853/1 "2019-11-21T10:13:55Z")

</div>

Got a Kibana 7.4.2 instance behind a HAproxy which fails to generate PDF reports and wondering howto debug this issue further.

Seeing this in my kibana log:

> {"type":"log","@timestamp":"2019-11-21T09:56:37Z","tags":["reporting","esqueue","queue-worker","warning"],"pid":2022,"message":"k38i5wsa01k6ff6300dx0l36 - Timeout processing job k38jbzsk01k6ff63004tgv7k"}  
> {"type":"log","@timestamp":"2019-11-21T09:56:37Z","tags":["reporting","esqueue","queue-worker","warning"],"pid":2022,"message":"k38i5wsa01k6ff6300dx0l36 - Timeout on job k38jbzsk01k6ff63004tgv7k"}  
> {"type":"log","@timestamp":"2019-11-21T09:56:37Z","tags":["reporting","esqueue","queue-worker","info"],"pid":2022,"message":"k38i5wsa01k6ff6300dx0l36 - Job execution completed successfully"}  
> {"type":"log","@timestamp":"2019-11-21T09:56:37Z","tags":["reporting","printable\_pdf","execute","k38jbzsk01k6ff63004tgv7k","error"],"pid":2022,"message":"waitForSelector .application failed on [http://kibana7:1080/perf7/s/tanium/app/canvas](http://kibana7:1080/perf7/s/tanium/app/canvas)"}

Seems like the headless processes are just waiting for something and then the queue manager process (here pid 2022) eventually decides to do a timeout, but why...

Got this kibana settings:

> server.port: 1080  
> server.host: "kibana7"  
> server.basePath: "/perf7"  
> server.rewriteBasePath: false

Wondering if using a basePath creates any issue for reporting...

---

<div class="post-metadata">

**Author:** ![Larry\_Gregory](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/larry_gregory/32/34969_2.png) [@Larry\_Gregory](https://discuss.elastic.co/u/Larry_Gregory)\
**Post date:** [November 21, 2019, 1:08pm UTC](https://discuss.elastic.co/t/reporting-generation-vs-timeout/208853/2 "2019-11-21T13:08:28Z")

</div>

Hey @stefws,

I wouldn't expect the base path to cause an issue for Reporting.  
Since you're running behind a reverse-proxy, can you try configuring the Reporting Server Settings, as described here?: [https://www.elastic.co/guide/en/kibana/current/reporting-settings-kb.html#reporting-kibana-server-settings](https://www.elastic.co/guide/en/kibana/current/reporting-settings-kb.html#reporting-kibana-server-settings)

If that doesn't help, then we can try to debug further by enabling verbose logging (set `logging.verbose: true` in your `kibana.yml`)

---

<div class="post-metadata">

**Author:** ![stefws](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/stefws/32/6442_2.png) [@stefws](https://discuss.elastic.co/u/stefws)\
**Post date:** [November 21, 2019, 2:45pm UTC](https://discuss.elastic.co/t/reporting-generation-vs-timeout/208853/3 "2019-11-21T14:45:04Z")

</div>

doesn't seem to change much with the xpack.reporting.kibanaServer keys defined  
With debug logging I get something like this:

> {"type":"log","@timestamp":"2019-11-21T14:37:44Z","tags":["debug","plugins","security","basic"],"pid":10717,"message":"Trying to authenticate user request to /api/reporting/generate/printablePdf?jobParams=(browserTimezone%3AAmerica%2FPhoenix%2Clayout%3A(dimensions%3A(height%3A720%2Cwidth%3A1080)%2Cid%3Apreserve\_layout)%2CobjectType%3A'canvas%20workpad'%2CrelativeUrls%3A!(%2Fapp%2Fcanvas%23%2Fexport%2Fworkpad%2Fpdf%2Fworkpad-5dd0a737-84b8-4a08-a2bd-a8bbb7a47fb7%2Fpage%2F1%2C%2Fapp%2Fcanvas%23%2Fexport%2Fworkpad%2Fpdf%2Fworkpad-5dd0a737-84b8-4a08-a2bd-a8bbb7a47fb7%2Fpage%2F2%2C%2Fapp%2Fcanvas%23%2Fexport%2Fworkpad%2Fpdf%2Fworkpad-5dd0a737-84b8-4a08-a2bd-a8bbb7a47fb7%2Fpage%2F3%2C%2Fapp%2Fcanvas%23%2Fexport%2Fworkpad%2Fpdf%2Fworkpad-5dd0a737-84b8-4a08-a2bd-a8bbb7a47fb7%2Fpage%2F4%2C%2Fapp%2Fcanvas%23%2Fexport%2Fworkpad%2Fpdf%2Fworkpad-5dd0a737-84b8-4a08-a2bd-a8bbb7a47fb7%2Fpage%2F5%2C%2Fapp%2Fcanvas%23%2Fexport%2Fworkpad%2Fpdf%2Fworkpad-5dd0a737-84b8-4a08-a2bd-a8bbb7a47fb7%2Fpage%2F6)%2Ctitle%3A'Test%20Report')."}  
> {"type":"log","@timestamp":"2019-11-21T14:37:44Z","tags":["debug","plugins","security","basic"],"pid":10717,"message":"Trying to authenticate via header."}  
> {"type":"log","@timestamp":"2019-11-21T14:37:44Z","tags":["debug","plugins","security","basic"],"pid":10717,"message":"Authorization header is not presented."}  
> {"type":"log","@timestamp":"2019-11-21T14:37:44Z","tags":["debug","plugins","security","basic"],"pid":10717,"message":"Trying to authenticate via state."}  
> {"type":"log","@timestamp":"2019-11-21T14:37:44Z","tags":["debug","plugins","security","basic"],"pid":10717,"message":"Request has been authenticated via state."}  
> {"type":"log","@timestamp":"2019-11-21T14:37:44Z","tags":["reporting","esqueue","queue-worker","debug"],"pid":10717,"message":"k38tldjb089pff63002r0feb - Job created in index .reporting-2019.11.17"}  
> {"type":"log","@timestamp":"2019-11-21T14:37:44Z","tags":["reporting","esqueue","queue-worker","debug"],"pid":10717,"message":"k38tldjb089pff63002r0feb - Job index refreshed .reporting-2019.11.17"}  
> {"type":"log","@timestamp":"2019-11-21T14:37:44Z","tags":["reporting","queue-job","info"],"pid":10717,"message":"Successfully queued job: k38tldjb089pff63002r0feb"}  
> {"type":"log","@timestamp":"2019-11-21T14:37:44Z","tags":["reporting","esqueue","queue-worker","debug"],"pid":10717,"message":"k38tfulm089pff63005pvc6w - 1 outstanding jobs returned"}  
> {"type":"log","@timestamp":"2019-11-21T14:37:45Z","tags":["reporting","esqueue","queue-worker","info"],"pid":10717,"message":"k38tfulm089pff63005pvc6w - Claimed job k38tldjb089pff63002r0feb"}  
> {"type":"log","@timestamp":"2019-11-21T14:37:45Z","tags":["reporting","esqueue","queue-worker","info"],"pid":10717,"message":"k38tfulm089pff63005pvc6w - Starting job"}  
> {"type":"log","@timestamp":"2019-11-21T14:37:45Z","tags":["reporting","browser-driver","debug"],"pid":10717,"message":"Creating browser driver factory"}  
> {"type":"log","@timestamp":"2019-11-21T14:37:45Z","tags":["reporting","browser-driver","debug"],"pid":10717,"message":"Browser driver factory created"}  
> {"type":"log","@timestamp":"2019-11-21T14:37:45Z","tags":["reporting","printable\_pdf","execute","k38tldjb089pff63002r0feb","info"],"pid":10717,"message":"opening url [http://kibana7.mxi.tdcfoo:1080/perf/s/tanium/app/canvas#/export/workpad/pdf/workpad-5dd0a737-84b8-4a08-a2bd-a8bbb7a47fb7/page/1?forceNow=2019-11-21T14%3A37%3A44.518Z](http://kibana7.mxi.tdcfoo:1080/perf/s/tanium/app/canvas#/export/workpad/pdf/workpad-5dd0a737-84b8-4a08-a2bd-a8bbb7a47fb7/page/1?forceNow=2019-11-21T14%3A37%3A44.518Z)"}  
> {"type":"log","@timestamp":"2019-11-21T14:37:45Z","tags":["reporting","printable\_pdf","execute","k38tldjb089pff63002r0feb","debug"],"pid":10717,"message":"Using custom headers for [http://kibana7.mxi.tdcfoo:1080/perf/s/tanium/app/canvas](http://kibana7.mxi.tdcfoo:1080/perf/s/tanium/app/canvas)"}  
> {"type":"log","@timestamp":"2019-11-21T14:37:45Z","tags":["license","debug","xpack"],"pid":10717,"message":"Calling [data] Elasticsearch \_xpack API. Polling frequency: 30001"}  
> {"type":"log","@timestamp":"2019-11-21T14:37:45Z","tags":["plugin","debug"],"pid":10717,"message":"Checking Elasticsearch version"}  
> {"type":"log","@timestamp":"2019-11-21T14:37:45Z","tags":["reporting","printable\_pdf","execute","k38tldjb089pff63002r0feb","browser","debug"],"pid":10717,"message":"Failed to load resource: the server responded with a status of 400 (Bad Request)"}  
> {"type":"log","@timestamp":"2019-11-21T14:37:45Z","tags":["reporting","printable\_pdf","execute","k38tldjb089pff63002r0feb","debug"],"pid":10717,"message":"waitForSelector .application"}

---

<div class="post-metadata">

**Author:** ![Larry\_Gregory](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/larry_gregory/32/34969_2.png) [@Larry\_Gregory](https://discuss.elastic.co/u/Larry_Gregory)\
**Post date:** [November 21, 2019, 2:48pm UTC](https://discuss.elastic.co/t/reporting-generation-vs-timeout/208853/4 "2019-11-21T14:48:39Z")

</div>

Thanks for the additional logs.

Nothing looks out of place, but I wish there was more detail around the "bad request" we're seeing. What happens if you navigate directly to [http://kibana7.mxi.tdcfoo:1080/perf/s/tanium/app/canvas#/export/workpad/pdf/workpad-5dd0a737-84b8-4a08-a2bd-a8bbb7a47fb7/page/1?forceNow=2019-11-21T14%3A37%3A44.518Z](http://kibana7.mxi.tdcfoo:1080/perf/s/tanium/app/canvas#/export/workpad/pdf/workpad-5dd0a737-84b8-4a08-a2bd-a8bbb7a47fb7/page/1?forceNow=2019-11-21T14%3A37%3A44.518Z) in your browser?

---

<div class="post-metadata">

**Author:** ![stefws](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/stefws/32/6442_2.png) [@stefws](https://discuss.elastic.co/u/stefws)\
**Post date:** [November 21, 2019, 2:52pm UTC](https://discuss.elastic.co/t/reporting-generation-vs-timeout/208853/5 "2019-11-21T14:52:03Z")

</div>

> [@Larry\_Gregory](#):
>
> [http://kibana7.mxi.tdcfoo:1080/perf/s/tanium/app/canvas#/export/workpad/pdf/workpad-5dd0a737-84b8-4a08-a2bd-a8bbb7a47fb7/page/1?forceNow=2019-11-21T14%3A37%3A44.518Z](http://kibana7.mxi.tdcfoo:1080/perf/s/tanium/app/canvas#/export/workpad/pdf/workpad-5dd0a737-84b8-4a08-a2bd-a8bbb7a47fb7/page/1?forceNow=2019-11-21T14%3A37%3A44.518Z))s/tanium/app/canvas#/export/workpad/pdf/workpad-5dd0a737-84b8-4a08-a2bd-a8bbb7a47fb7/page/1?forceNow=2019-11-21T14%3A37%3A44.518Z

Shows me the first page of the requested report in Workpad of Canvas

---

<div class="post-metadata">

**Author:** ![Larry\_Gregory](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/larry_gregory/32/34969_2.png) [@Larry\_Gregory](https://discuss.elastic.co/u/Larry_Gregory)\
**Post date:** [November 21, 2019, 4:27pm UTC](https://discuss.elastic.co/t/reporting-generation-vs-timeout/208853/6 "2019-11-21T16:27:33Z")

</div>

@stefws Thanks for testing.

What does your HAProxy setup look like? Is it doing anything with authentication, or manipulating the requests in any way?

Can you check the HAProxy logs and see what it's saying about that request? Is it possible that HAProxy is responding with the `400` instead of Kibana?

---

<div class="post-metadata">

**Author:** ![stefws](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/stefws/32/6442_2.png) [@stefws](https://discuss.elastic.co/u/stefws)\
**Post date:** [November 22, 2019, 6:56am UTC](https://discuss.elastic.co/t/reporting-generation-vs-timeout/208853/7 "2019-11-22T06:56:24Z")

</div>

Well the HAproxy terminates the SSL and load balances over a pair of Nginx proxies used prior to xpacks included in the basic license to perform user authentication. Same setup are now used to proxy to various kibana instances, hence the use of server.basePath.

Not believing neither haproxy nor nginx to be involved in reporting as xpack.reporting.kibanaServer.\* are pointing directly at the local kibana instance listening IP.

> [root@kibana7 ~]# netstat -lntp | grep node  
> tcp 0 0 10.45.69.65:1080 0.0.0.0:\* LISTEN 11510/node  
> [root@kibana7 ~]# ping kibana7.mxi.tdcfoo  
> PING kibana7.mxi.tdcfoo (10.45.69.65) 56(84) bytes of data.  
> 64 bytes from kibana7.mxi.tdcfoo (10.45.69.65): icmp\_seq=1 ttl=64 time=0.020 ms  
> 64 bytes from kibana7.mxi.tdcfoo (10.45.69.65): icmp\_seq=2 ttl=64 time=0.012 ms  
> ^C

---

<div class="post-metadata">

**Author:** ![stefws](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/stefws/32/6442_2.png) [@stefws](https://discuss.elastic.co/u/stefws)\
**Post date:** [November 27, 2019, 2:17pm UTC](https://discuss.elastic.co/t/reporting-generation-vs-timeout/208853/8 "2019-11-27T14:17:21Z")

</div>

Latest error when attempting to generate a PDF:

 ![16](https://us1.discourse-cdn.com/elastic/original/3X/a/e/ae18384ce81a09879b79d39dde7a378f5b2ba842.png)

```
{"type":"error","@timestamp":"2019-11-27T13:53:07Z","tags":["reporting","printable_pdf","execute","k3hckhuf0jfh352e5dfhh12l","error"],"pid":718,"level":"error","error":{"message":"Request to [http://kibana7.mxi.tdcfoo:1080/perf5/login?next=%2Fperf5%2Fperf5%2Flogin%3Fnext%3D%252Fperf5%252Fperf5%252Flogin%253Fnext%253D%25252Fperf5%25252Fperf5%25252Flogin%25253Fnext%25253D%2525252Fperf5%2525252Fperf5%2525252Flogin%2525253Fnext%2525253D ... %2Fapp%2525252525252525252525252525252525252Fcanvas] failed! [net::ERR_TOO_MANY_REDIRECTS]","name":"Error","stack":"Error: Request to [http://kibana7.mxi.tdcfoo:1080/perf5/login?next=%2Fperf5%2Fperf5%2Flogin%3Fnext%3D%252Fperf5%252Fperf5%252Flogin%253Fnext%253D%25252Fperf5%25252Fperf5%25252Flogin%25253Fnext%25253D%2525252Fperf5%2525252Fperf5%2525252Flogin ... %2Fapp%2525252525252525252525252525252525252Fcanvas] failed! [net::ERR_TOO_MANY_REDIRECTS]\n at MergeMapSubscriber.Rx.fromEvent.pipe.req [as project] (/usr/share/kibana/x-pack/legacy/plugins/reporting/server/browsers/chromium/driver_factory/index.js:159:32)\n at MergeMapSubscriber._tryNext (/usr/share/kibana/node_modules/rxjs/internal/operators/mergeMap.js:65:27)\n at MergeMapSubscriber._next (/usr/share/kibana/node_modules/rxjs/internal/operators/mergeMap.js:55:18)\n at MergeMapSubscriber.Subscriber.next (/usr/share/kibana/node_modules/rxjs/internal/Subscriber.js:64:18)\n at Page.handler (/usr/share/kibana/node_modules/rxjs/internal/observable/fromEvent.js:22:28)\n at Page.emit (events.js:189:13)\n at NetworkManager.Page.networkManager.on.event (/usr/share/kibana/node_modules/puppeteer-core/lib/Page.js:112:74)\n at NetworkManager.emit (events.js:189:13)\n at NetworkManager._onLoadingFailed (/usr/share/kibana/node_modules/puppeteer-core/lib/NetworkManager.js:315:10)\n at CDPSession.emit (events.js:189:13)\n at CDPSession._onMessage (/usr/share/kibana/node_modules/puppeteer-core/lib/Connection.js:200:12)\n at Connection._onMessage (/usr/share/kibana/node_modules/puppeteer-core/lib/Connection.js:112:17)\n at PipeTransport._dispatch (/usr/share/kibana/node_modules/puppeteer-core/lib/PipeTransport.js:61:22)\n at Socket.PipeTransport._eventListeners.helper.addEventListener.buffer (/usr/share/kibana/node_modules/puppeteer-core/lib/PipeTransport.js:30:64)\n at Socket.emit (events.js:189:13)\n at addChunk (_stream_readable.js:284:12)"},"message":"Request to [http://kibana7.mxi.tdcfoo:1080/perf5/login?next=%2Fperf5%2Fperf5%2Flogin%3Fnext%3D%252Fperf5%252Fperf5%252Flogin%253Fnext%253D%25252Fperf5%25252Fperf5%25252Flogin%25253Fnext%25253D%2525252Fperf5%2525252Fperf5%2525252Flogin%2525253Fnext%2525253D%252525252Fperf5%252525252Fperf5%252525252Flogin%252525253Fnext%252525253D%25252525252Fperf5%25252525252Fperf5%25252525252Flogin%25252525253Fnext%25252525253D%2525252525252Fperf5%2525252525252Fperf5%2525252525252Flogin%2525252525253Fnext%2525252525253D%252525252525252Fperf5%252525252525252Fperf5%... 2Fapp%2525252525252525252525252525252525252Fcanvas] failed! [net::ERR_TOO_MANY_REDIRECTS]"}
{"type":"log","@timestamp":"2019-11-27T13:53:07Z","tags":["reporting","esqueue","queue-worker","error"],"pid":718,"message":"k3fxi1j200jyff6300c7c5o8 - Failure occurred on job k3hckhuf0jfh352e5dfhh12l: Error: Request to [http://kibana7.mxi.tdcfoo:1080/perf5/login?next=%2Fperf5%2Fperf5%2Flogin%3Fnext%3D%252Fperf5%252Fperf5%252Flogin%253Fnext%253D%25252Fperf5%25252Fperf5%25252Flogin%25253Fnext%25253D%2525252Fperf5%2525252Fperf5%2525252Flogin%2525253Fnext%2525253D%252525252Fperf5%252525252Fperf5%252525252Flogin%252525253Fnext%252525253D%25252525252Fperf5%25252525252Fperf5%25252525252Flogin%25252525253Fnext%25252525253D%2525252525252Fperf5%2525252525252Fperf5%2525252525252Flogin%2525252525253Fnext%2525252525253D%252525252525252Fperf5%252525252525252Fperf5%252525252525252Flogin%252525252525253Fnext%252525252525253D%25252525252525252Fperf5%25252525252525252Fperf5%25252525252525252Flogin%25252525252525253Fnext%25252525252525253D%2525252525252525252Fperf5%2525252525252525252Fperf5%2525252525252525252Flogin%2525252525252525253Fnext%2525252525252525253D%252525252525252525252Fperf5%252525252525252525252Fperf5%252525252...8)\n at Page.handler (/usr/share/kibana/node_modules/rxjs/internal/observable/fromEvent.js:22:28)\n at Page.emit (events.js:189:13)\n at NetworkManager.Page.networkManager.on.event (/usr/share/kibana/node_modules/puppeteer-core/lib/Page.js:112:74)\n at NetworkManager.emit (events.js:189:13)\n at NetworkManager._onLoadingFailed (/usr/share/kibana/node_modules/puppeteer-core/lib/NetworkManager.js:315:10)\n at CDPSession.emit (events.js:189:13)\n at CDPSession._onMessage (/usr/share/kibana/node_modules/puppeteer-core/lib/Connection.js:200:12)\n at Connection._onMessage (/usr/share/kibana/node_modules/puppeteer-core/lib/Connection.js:112:17)\n at PipeTransport._dispatch (/usr/share/kibana/node_modules/puppeteer-core/lib/PipeTransport.js:61:22)\n at Socket.PipeTransport._eventListeners.helper.addEventListener.buffer (/usr/share/kibana/node_modules/puppeteer-core/lib/PipeTransport.js:30:64)\n at Socket.emit (events.js:189:13)\n at addChunk (_stream_readable.js:284:12)"}
{"type":"log","@timestamp":"2019-11-27T13:53:07Z","tags":["reporting","esqueue","queue-worker","error"],"pid":718,"message":"A partial version of the entire error message was logged. The entire error message length is: 4077 characters."}
```

---

<div class="post-metadata">

**Author:** ![stefws](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/stefws/32/6442_2.png) [@stefws](https://discuss.elastic.co/u/stefws)\
**Post date:** [November 28, 2019, 12:26pm UTC](https://discuss.elastic.co/t/reporting-generation-vs-timeout/208853/9 "2019-11-28T12:26:26Z")

</div>

I succeed generating PDFs if configuring Kibana without HA+Nginx proxies, seems using server.basePath (removed by my proxy) causes an issue when pointing reporting directly to local kibana listening socket behind nginx proxies maybe because kibana referrals includes basePath 🙂

---

<div class="post-metadata">

**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\
**Post date:** [December 26, 2019, 12:26pm UTC](https://discuss.elastic.co/t/reporting-generation-vs-timeout/208853/10 "2019-12-26T12:26:33Z")

</div>

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.
