Kibana: Can't generate PDF with Chromium on Ubuntu 16.04

Created on 26 Sep 2018  路  9Comments  路  Source: elastic/kibana

Kibana version: 6.5.0-SNAPSHOT

Elasticsearch version: 6.5.0-SNAPSHOT

Server OS version: Ubuntu 16.04

Browser version: Chrome

Browser OS version: Ubuntu 16.04

Original install method (e.g. download page, yum, from source, etc.): .deb packages

Describe the bug: PDF reporting fails with Error: Chromium exited with code: undefined. undefined

Steps to reproduce:

  1. I tried to print just a simple visualization but it failed with that error
  2. Generating CSV report from Discover works
    3.

Expected behavior:

Screenshots (if relevant):

Errors in browser console (if relevant):

Provide logs and/or server output (if relevant):
Here's part of the log;

Sep 26 02:07:04 vagrant kibana[7539]: {"type":"log","@timestamp":"1970-01-01T00:00:00Z","tags":["debug","legacy","proxy"],"pid":7539,"message":"Event is being forwarded: connection"}
Sep 26 02:07:04 vagrant kibana[7539]: {"type":"log","@timestamp":"1970-01-01T00:00:00Z","tags":["debug","legacy","proxy"],"pid":7539,"message":"Event is being forwarded: clientError"}
Sep 26 02:07:04 vagrant kibana[7539]: {"type":"log","@timestamp":"2018-09-26T02:07:04Z","tags":["debug","connection","econnreset"],"pid":7539,"message":"ECONNRESET: Socket was closed by the client (probably the browser) before it could be read completely"}
Sep 26 02:07:04 vagrant kibana[7539]: {"type":"log","@timestamp":"2018-09-26T02:07:04Z","tags":["reporting","esqueue","worker","warn"],"pid":7539,"message":"jmiab4qp05tf8f5fe5dkl4ab - Failure occurred on job jmiieags05tf8f5fe57qpbu5: Error: Chromium exited with code: undefined. undefined\n    at MergeMapSubscriber.Rx.fromEvent.pipe.err [as project]

And a larger chunk;
temp.log

Any additional context:
PDF reporting worked on this SAML config with 6.4.2 with the default PhantomJS. We used the optional Chromium reporting on some configurations on 6.4.2 but not this SAML one.

I went back to the latest 6.4.2 on this SAML setup. PDF reporting works with the default PhantomJS configuration but fails with a similar error when I set
xpack.reporting.capture.browser.type: chromium
The error in the Reporting UI is Error: socket hang up
So not a regression from the optional chromium settings in 6.4, but now chromium is the default, and I don't know if phantomJS is optional going forward?

Reporting KibanaApp bug
Source
picture LeeDr

All 9 comments

Adding this in the kibana.yml didn't help. Same error.
xpack.reporting.capture.browser.chromium.disableSandbox: true

Setting this did work. But this solution won't work if we remove the phantom option in 7.0.
xpack.reporting.capture.browser.type: phantom

LeeDr picture LeeDr on 27 Sep 2018
👍1

I've set up a new VM without SAML authentication and I still get the same error;
Error: Chromium exited with code: undefined. undefined

But I do have a test running on Ubuntu 14.04 and PDF reporting works fine there with Chromium.

I've also discovered that PDF Reporting for Canvas will not work with PhantomJS.

LeeDr picture LeeDr on 28 Sep 2018

I've narrowed the issue down further.

Chromium reporting fails on a private ubuntu 16.04 virtualbox that we set up to be able to run selenium tests on the desktop. But succeeds on the standard "elastic/ubuntu-16.04-x86_64".

I don't have any thoughts yet on why. The install of Kibana is the same on both.

LeeDr picture LeeDr on 28 Sep 2018

I'm seeing somewhat different behavior now on the latest 6.5.0-SNAPSHOT build on the SAML configuration. Now the .watcher-history just has "messages":["Watch is already queued in thread pool"]

And the Kibana log contains this;

"message":"There was an error fetching the SSO data. This could simply mean that there was a problem with the network. But, if a \"Origin\" error has been logged before this warning, please add \"https://elastic-dev.auth0.com\" to the \"Allowed Origins (CORS)\" list in the Auth0 dashboard: https://manage.auth0.com/#/applications/SkhHyn1y5sLWB3Q5UzOJjXJn0Pb7PA16/settings"}

But I did already add https://elastic-dev.auth0.com to the "Allowed Origins (CORS)" list in the Auth0 dashboard a few days ago after seeing that message.

More of the log;

Oct 31 21:51:57 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:51:57Z","tags":["debug","stats-collection"],"pid":7795,"message":"Fetching data from reporting collector"}
Oct 31 21:52:07 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:07Z","tags":["debug","stats-collection"],"pid":7795,"message":"Fetching data from reporting collector"}
Oct 31 21:52:17 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:17Z","tags":["debug","stats-collection"],"pid":7795,"message":"Fetching data from reporting collector"}
Oct 31 21:52:24 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:24Z","tags":["reporting","esqueue","worker","warn"],"pid":7795,"message":"jnxnx4gl060j8f5fe5dxswzp - Timeout processing job jnxoc7sh060j8f5fe5gj51nc"}
Oct 31 21:52:24 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:24Z","tags":["reporting","esqueue","worker","warn"],"pid":7795,"message":"jnxnx4gl060j8f5fe5dxswzp - Timeout on job jnxoc7sh060j8f5fe5gj51nc"}
Oct 31 21:52:24 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:24Z","tags":["reporting","worker","debug"],"pid":7795,"message":"PDF: Job timeout exceeded: (jnxoc7sh060j8f5fe5gj51nc)"}
Oct 31 21:52:27 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:27Z","tags":["reporting","esqueue","worker","debug"],"pid":7795,"message":"jnxnx4gl060j8f5fe5dxswzp - 7 outstanding jobs returned"}
Oct 31 21:52:27 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:27Z","tags":["reporting","esqueue","worker","debug"],"pid":7795,"message":"jnxnx4gl060j8f5fe5dxswzp - Claimed job jnxoc7sh060j8f5fe5gj51nc"}
Oct 31 21:52:27 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:27Z","tags":["reporting","esqueue","worker","debug"],"pid":7795,"message":"jnxnx4gl060j8f5fe5dxswzp - Starting job jnxoc7sh060j8f5fe5gj51nc"}
Oct 31 21:52:27 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:27Z","tags":["reporting","worker","debug"],"pid":7795,"message":"PDF: Processing PDF job"}
Oct 31 21:52:27 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:27Z","tags":["reporting","screenshots","debug"],"pid":7795,"message":"Creating browser driver factory"}
Oct 31 21:52:27 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:27Z","tags":["debug","stats-collection"],"pid":7795,"message":"Fetching data from reporting collector"}
Oct 31 21:52:28 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:28Z","tags":["reporting","screenshots","debug"],"pid":7795,"message":"Driver factory created"}
Oct 31 21:52:28 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:28Z","tags":["reporting","screenshots","debug"],"pid":7795,"message":"opening https://localhost:5601/app/kibana#/visualize/edit/Latency-histogram?_g=(refreshInterval%3A(pause%3A!t%2Cvalue%3A0)%2Ctime%3A(from%3Anow-24h%2Cmode%3Aquick%2Cto%3Anow))&_a=(filters%3A!()%2Clinked%3A!t%2Cquery%3A(language%3Alucene%2Cquery%3A'')%2CuiState%3A()%2Cvis%3A(aggs%3A!((enabled%3A!t%2Cid%3A'1'%2Cparams%3A()%2Cschema%3Ametric%2Ctype%3Acount)%2C(enabled%3A!t%2Cid%3A'2'%2Cparams%3A(extended_bounds%3A()%2Cfield%3Aresponsetime%2Cinterval%3A10)%2Cschema%3Asegment%2Ctype%3Ahistogram))%2Cparams%3A(addLegend%3A!t%2CaddTimeMarker%3A!f%2CaddTooltip%3A!t%2CcategoryAxes%3A!((id%3ACategoryAxis-1%2Clabels%3A(show%3A!t%2Ctruncate%3A100)%2Cposition%3Abottom%2Cscale%3A(type%3Alinear)%2Cshow%3A!t%2Cstyle%3A()%2Ctitle%3A()%2Ctype%3Acategory))%2CdefaultYExtents%3A!f%2Cgrid%3A(categoryLines%3A!f%2Cstyle%3A(color%3A%23eee))%2Cinterpolate%3Alinear%2ClegendPosition%3Aright%2Cmode%3Astacked%2Cscale%3Alinear%2CseriesParams%3A!((data%3A(id%3A'1'%2Clabel%3ACount)%2Cinterpolate%3Acardinal%2Cmode%3Astacked%2Cshow%3Atrue%2Ctype%3Aarea%2CvalueAxis%3AValueAxis-1))%2CsetYExtents%3A!f%2CshareYAxis%3A!t%2CsmoothLines%3A!t%2Ctimes%3A!()%2Ctype%3Aarea%2CvalueAxes%3A!((id%3AValueAxis-1%2Clabels%3A(filter%3A!f%2Crotate%3A0%2Cshow%3A!t%2Ctruncate%3A100)%2Cname%3ALeftAxis-1%2Cposition%3Aleft%2Cscale%3A(defaultYExtents%3A!f%2Cmode%3Anormal%2CsetYExtents%3A!f%2Ctype%3Alinear)%2Cshow%3A!t%2Cstyle%3A()%2Ctitle%3A(text%3ACount)%2Ctype%3Avalue))%2CyAxis%3A())%2Ctitle%3A'Latency%20histogram'%2Ctype%3Aarea))&forceNow=2018-10-31T21%3A29%3A36.113Z"}
Oct 31 21:52:28 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:28Z","tags":["reporting","screenshots","debug"],"pid":7795,"message":"Configured page"}
Oct 31 21:52:34 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:34Z","tags":["reporting","screenshots","browserConsole","debug"],"pid":7795,"message":"There was an error fetching the SSO data. This could simply mean that there was a problem with the network. But, if a \"Origin\" error has been logged before this warning, please add \"https://elastic-dev.auth0.com\" to the \"Allowed Origins (CORS)\" list in the Auth0 dashboard: https://manage.auth0.com/#/applications/SkhHyn1y5sLWB3Q5UzOJjXJn0Pb7PA16/settings"}
Oct 31 21:52:34 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:34Z","tags":["reporting","screenshots","debug"],"pid":7795,"message":"Page opened with status success"}
Oct 31 21:52:34 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:34Z","tags":["reporting","screenshots","debug"],"pid":7795,"message":"PhantomDriver: waitForSelector .application"}
Oct 31 21:52:36 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:36Z","tags":["trace","legacy","service"],"pid":7795,"message":"Request will be handled by proxy GET:/api/reporting/jobs/download/jnxoin88060j8f5fe58v9duu."}
Oct 31 21:52:36 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:36Z","tags":["debug","security","basic"],"pid":7795,"message":"Trying to authenticate user request to /api/reporting/jobs/download/jnxoin88060j8f5fe58v9duu."}
Oct 31 21:52:36 vagrant kibana[7795]: {"type":"response","@timestamp":"2018-10-31T21:52:36Z","tags":[],"pid":7795,"method":"get","statusCode":503,"req":{"url":"/api/reporting/jobs/download/jnxoin88060j8f5fe58v9duu","method":"get","headers":{"accept-charset":"UTF-8","kbn-xsrf":"reporting","content-length":"0","host":"localhost:5601","connection":"Keep-Alive","user-agent":"Apache-HttpClient/4.5.2 (Java/1.8.0_121)","accept-encoding":"gzip,deflate"},"remoteAddress":"127.0.0.1","userAgent":"127.0.0.1"},"res":{"statusCode":503,"responseTime":20,"contentLength":9},"message":"GET /api/reporting/jobs/download/jnxoin88060j8f5fe58v9duu 503 20ms - 9.0B"}
Oct 31 21:52:36 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:36Z","tags":["trace","legacy","service"],"pid":7795,"message":"Request will be handled by proxy GET:/api/reporting/jobs/download/jnxojxps060j8f5fe5cym9gg."}
Oct 31 21:52:36 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:36Z","tags":["debug","security","basic"],"pid":7795,"message":"Trying to authenticate user request to /api/reporting/jobs/download/jnxojxps060j8f5fe5cym9gg."}
Oct 31 21:52:36 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:36Z","tags":["trace","legacy","service"],"pid":7795,"message":"Request will be handled by proxy GET:/api/reporting/jobs/download/jnxohczf060j8f5fe59z2yxd."}
Oct 31 21:52:36 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:36Z","tags":["debug","security","basic"],"pid":7795,"message":"Trying to authenticate user request to /api/reporting/jobs/download/jnxohczf060j8f5fe59z2yxd."}
Oct 31 21:52:36 vagrant kibana[7795]: {"type":"response","@timestamp":"2018-10-31T21:52:36Z","tags":[],"pid":7795,"method":"get","statusCode":503,"req":{"url":"/api/reporting/jobs/download/jnxojxps060j8f5fe5cym9gg","method":"get","headers":{"accept-charset":"UTF-8","kbn-xsrf":"reporting","content-length":"0","host":"localhost:5601","connection":"Keep-Alive","user-agent":"Apache-HttpClient/4.5.2 (Java/1.8.0_121)","accept-encoding":"gzip,deflate"},"remoteAddress":"127.0.0.1","userAgent":"127.0.0.1"},"res":{"statusCode":503,"responseTime":23,"contentLength":9},"message":"GET /api/reporting/jobs/download/jnxojxps060j8f5fe5cym9gg 503 23ms - 9.0B"}
Oct 31 21:52:36 vagrant kibana[7795]: {"type":"response","@timestamp":"2018-10-31T21:52:36Z","tags":[],"pid":7795,"method":"get","statusCode":503,"req":{"url":"/api/reporting/jobs/download/jnxohczf060j8f5fe59z2yxd","method":"get","headers":{"accept-charset":"UTF-8","kbn-xsrf":"reporting","content-length":"0","host":"localhost:5601","connection":"Keep-Alive","user-agent":"Apache-HttpClient/4.5.2 (Java/1.8.0_121)","accept-encoding":"gzip,deflate"},"remoteAddress":"127.0.0.1","userAgent":"127.0.0.1"},"res":{"statusCode":503,"responseTime":19,"contentLength":9},"message":"GET /api/reporting/jobs/download/jnxohczf060j8f5fe59z2yxd 503 19ms - 9.0B"}
Oct 31 21:52:37 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:37Z","tags":["debug","stats-collection"],"pid":7795,"message":"Fetching data from reporting collector"}
Oct 31 21:52:37 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:37Z","tags":["trace","legacy","service"],"pid":7795,"message":"Request will be handled by proxy GET:/api/reporting/jobs/download/jnxog2w2060j8f5fe5ebwdrn."}
Oct 31 21:52:37 vagrant kibana[7795]: {"type":"log","@timestamp":"2018-10-31T21:52:37Z","tags":["debug","security","basic"],"pid":7795,"message":"Trying to authenticate user request to /api/reporting/jobs/download/jnxog2w2060j8f5fe5ebwdrn."}
Oct 31 21:52:37 vagrant kibana[7795]: {"type":"response","@timestamp":"2018-10-31T21:52:37Z","tags":[],"pid":7795,"method":"get","statusCode":503,"req":{"url":"/api/reporting/jobs/download/jnxog2w2060j8f5fe5ebwdrn","method":"get","headers":{"accept-charset":"UTF-8","kbn-xsrf":"reporting","content-length":"0","host":"localhost:5601","connection":"Keep-Alive","user-agent":"Apache-HttpClient/4.5.2 (Java/1.8.0_121)","accept-encoding":"gzip,deflate"},"remoteAddress":"127.0.0.1","userAgent":"127.0.0.1"},"res":{"statusCode":503,"responseTime":26,"contentLength":9},"message":"GET /api/reporting/jobs/download/jnxog2w2060j8f5fe5ebwdrn 503 26ms - 9.0B"}
LeeDr picture LeeDr on 31 Oct 2018

Left the SAML config and built the VM without security and still get;
"Error: Chromium exited with code: undefined. undefined\"

LeeDr picture LeeDr on 31 Oct 2018

This looks like it's caused by some difference between the ubuntu and unbuntu desktop vagrant boxes I'm using. The main elastic one works while the customized (older) desktop one doesn't even though all the stack setup is the same. I'm still investigating.

LeeDr picture LeeDr on 1 Nov 2018
👍1

Here's the logging related to Chromium for one PDF reporting job.

May 03 21:40:18 vagrant kibana[7692]: {"type":"log","@timestamp":"2019-05-03T21:40:18Z","tags":["reporting","browser-driver","chromium-driver-factory","headless-chromium-driver","debug"],"pid":7692,"message":"opening url https://0.0.0.0:5601/app/kibana#/visualize/edit/Container-CPU-usage-ecs?_g=(refreshInterval%3A(pause%3A!t%2Cvalue%3A0)%2Ctime%3A(from%3A'2019-04-30T22%3A18%3A49.408Z'%2Cto%3A'2019-05-04T10%3A36%3A25.515Z'))&_a=(filters%3A!()%2Clinked%3A!f%2Cquery%3A(language%3Alucene%2Cquery%3A(query_string%3A(analyze_wildcard%3A!t%2Cquery%3A'*')))%2CuiState%3A(vis%3A(params%3A(sort%3A(columnIndex%3A!n%2Cdirection%3A!n))))%2Cvis%3A(aggs%3A!((enabled%3A!t%2Cid%3A'1'%2Cparams%3A(customLabel%3A'CPU%20user'%2Cfield%3Asystem.process.cgroup.cpuacct.stats.user.ns)%2Cschema%3Ametric%2Ctype%3Amax)%2C(enabled%3A!t%2Cid%3A'2'%2Cparams%3A(customLabel%3A'CPU%20quota'%2Cfield%3Asystem.process.cgroup.cpu.cfs.quota.us)%2Cschema%3Ametric%2Ctype%3Amax)%2C(enabled%3A!t%2Cid%3A'3'%2Cparams%3A(customLabel%3A'Container%20ID'%2Cfield%3Asystem.process.cgroup.id%2CmissingBucket%3A!f%2CmissingBucketLabel%3AMissing%2Corder%3Adesc%2CorderBy%3A'1'%2CotherBucket%3A!f%2CotherBucketLabel%3AOther%2Csize%3A5)%2Cschema%3Abucket%2Ctype%3Aterms)%2C(enabled%3A!t%2Cid%3A'4'%2Cparams%3A(customLabel%3A'CPU%20throttling'%2Cfield%3Asystem.process.cgroup.cpu.stats.throttled.ns)%2Cschema%3Ametric%2Ctype%3Amax)%2C(enabled%3A!t%2Cid%3A'5'%2Cparams%3A(customLabel%3A'CPU%20kernel'%2Cfield%3Asystem.process.cgroup.cpuacct.stats.system.ns)%2Cschema%3Ametric%2Ctype%3Amax)%2C(enabled%3A!t%2Cid%3A'6'%2Cparams%3A(customLabel%3A'Process%20name'%2Cfield%3Aprocess.name%2CmissingBucket%3A!f%2CmissingBucketLabel%3AMissing%2Corder%3Adesc%2CorderBy%3A'1'%2CotherBucket%3A!f%2CotherBucketLabel%3AOther%2Csize%3A5)%2Cschema%3Abucket%2Ctype%3Aterms))%2Cparams%3A(perPage%3A10%2CshowMetricsAtAllLevels%3A!f%2CshowPartialRows%3A!f%2CshowTotal%3A!f%2Csort%3A(columnIndex%3A!n%2Cdirection%3A!n)%2CtotalFunc%3Asum)%2Ctitle%3A'Container%20CPU%20usage%20%5BMetricbeat%20System%5D%20ECS'%2Ctype%3Atable))&forceNow=2019-05-03T21%3A
May 03 21:40:18 vagrant kibana[7692]: {"type":"log","@timestamp":"2019-05-03T21:40:18Z","tags":["reporting","browser-driver","chromium-driver-factory","headless-chromium-driver","debug"],"pid":7692,"message":"Using custom headers for https://0.0.0.0:5601/app/kibana"}
May 03 21:40:18 vagrant kibana[7692]: {"type":"log","@timestamp":"2019-05-03T21:40:18Z","tags":["reporting","esqueue","worker","warn"],"pid":7692,"message":"jv8krxfe05xo8f5fe5de62al - Failure occurred on job jv8lqoou05xo8f5fe57px37s: Error: Chromium exited with: [{}]
    at MergeMapSubscriber.Rx.fromEvent.pipe.code [as project] (/usr/share/kibana/node_modules/x-pack/plugins/reporting/server/browsers/chromium/driver_factory/index.js:126:42)
    at MergeMapSubscriber._tryNext (/usr/share/kibana/node_modules/rxjs/internal/operators/mergeMap.js:65:27)
    at MergeMapSubscriber._next (/usr/share/kibana/node_modules/rxjs/internal/operators/mergeMap.js:55:18)
    at MergeMapSubscriber.Subscriber.next (/usr/share/kibana/node_modules/rxjs/internal/Subscriber.js:64:18)
    at Browser.handler (/usr/share/kibana/node_modules/rxjs/internal/observable/fromEvent.js:22:28)
    at Browser.emit (events.js:189:13)
    at Connection.Browser._connection.setClosedCallback (/usr/share/kibana/node_modules/puppeteer-core/lib/Browser.js:49:12)
    at Connection._onClose (/usr/share/kibana/node_modules/puppeteer-core/lib/Connection.js:133:12)
    at WebSocket.emit (events.js:189:13)
    at WebSocket.emitClose (/usr/share/kibana/node_modules/ws/lib/websocket.js:172:10)
    at Socket.socketOnClose (/usr/share/kibana/node_modules/ws/lib/websocket.js:781:15)
    at Socket.emit (events.js:189:13)
    at TCP._handle.close (net.js:600:12)"}
May 03 21:40:18 vagrant kibana[7692]: {"type":"error","@timestamp":"2019-05-03T21:40:18Z","tags":["warning","process"],"pid":7692,"level":"error","error":{"message":"Error: WebSocket is not open: readyState 3 (CLOSED)
    at WebSocket.send (/usr/share/kibana/node_modules/ws/lib/websocket.js:314:19)
    at Connection.send (/usr/share/kibana/node_modules/puppeteer-core/lib/Connection.js:84:21)
    at gracefullyCloseChrome (/usr/share/kibana/node_modules/puppeteer-core/lib/Launcher.js:191:20)
    at Browser.close (/usr/share/kibana/node_modules/puppeteer-core/lib/Browser.js:208:31)
    at Object.kill (/usr/share/kibana/node_modules/x-pack/plugins/reporting/server/browsers/chromium/driver_factory/index.js:90:25)
    at Subscription.observer.add (/usr/share/kibana/node_modules/x-pack/plugins/reporting/server/browsers/safe_child_process.js:53:18)
    at Subscription.tryCatcher (/usr/share/kibana/node_modules/rxjs/internal/util/tryCatch.js:7:31)
    at Subscription.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscription.js:37:59)
    at Subscription.tryCatcher (/usr/share/kibana/node_modules/rxjs/internal/util/tryCatch.js:7:31)
    at InnerSubscriber.Subscription.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscription.js:50:70)
    at InnerSubscriber.Subscriber.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscriber.js:84:38)
    at InnerSubscriber.tryCatcher (/usr/share/kibana/node_modules/rxjs/internal/util/tryCatch.js:7:31)
    at MergeMapSubscriber.Subscription.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscription.js:50:70)
    at MergeMapSubscriber.Subscriber.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscriber.js:84:38)
    at MergeMapSubscriber.tryCatcher (/usr/share/kibana/node_modules/rxjs/internal/util/tryCatch.js:7:31)
    at TapSubscriber.Subscription.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscription.js:50:70)
    at TapSubscriber.Subscriber.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscriber.js:84:38)
    at TapSub
May 03 21:40:18 vagrant kibana[7692]: scriber.tryCatcher (/usr/share/kibana/node_modules/rxjs/internal/util/tryCatch.js:7:31)
    at MergeMapSubscriber.Subscription.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscription.js:50:70)
    at MergeMapSubscriber.Subscriber.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscriber.js:84:38)
    at MergeMapSubscriber.tryCatcher (/usr/share/kibana/node_modules/rxjs/internal/util/tryCatch.js:7:31)
    at TakeSubscriber.Subscription.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscription.js:50:70)","name":"UnhandledPromiseRejectionWarning","stack":"UnhandledPromiseRejectionWarning: Error: WebSocket is not open: readyState 3 (CLOSED)
    at WebSocket.send (/usr/share/kibana/node_modules/ws/lib/websocket.js:314:19)
    at Connection.send (/usr/share/kibana/node_modules/puppeteer-core/lib/Connection.js:84:21)
    at gracefullyCloseChrome (/usr/share/kibana/node_modules/puppeteer-core/lib/Launcher.js:191:20)
    at Browser.close (/usr/share/kibana/node_modules/puppeteer-core/lib/Browser.js:208:31)
    at Object.kill (/usr/share/kibana/node_modules/x-pack/plugins/reporting/server/browsers/chromium/driver_factory/index.js:90:25)
    at Subscription.observer.add (/usr/share/kibana/node_modules/x-pack/plugins/reporting/server/browsers/safe_child_process.js:53:18)
    at Subscription.tryCatcher (/usr/share/kibana/node_modules/rxjs/internal/util/tryCatch.js:7:31)
    at Subscription.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscription.js:37:59)
    at Subscription.tryCatcher (/usr/share/kibana/node_modules/rxjs/internal/util/tryCatch.js:7:31)
    at InnerSubscriber.Subscription.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscription.js:50:70)
    at InnerSubscriber.Subscriber.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscriber.js:84:38)
    at InnerSubscriber.tryCatcher (/usr/share/kibana/node_modules/rxjs/internal/util/tryCatch.js:7:31)
    at MergeMapSubscriber.Subscription.unsubscribe (/usr/share/kibana/node_mod
May 03 21:40:18 vagrant kibana[7692]: ules/rxjs/internal/Subscription.js:50:70)
    at MergeMapSubscriber.Subscriber.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscriber.js:84:38)
    at MergeMapSubscriber.tryCatcher (/usr/share/kibana/node_modules/rxjs/internal/util/tryCatch.js:7:31)
    at TapSubscriber.Subscription.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscription.js:50:70)
    at TapSubscriber.Subscriber.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscriber.js:84:38)
    at TapSubscriber.tryCatcher (/usr/share/kibana/node_modules/rxjs/internal/util/tryCatch.js:7:31)
    at MergeMapSubscriber.Subscription.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscription.js:50:70)
    at MergeMapSubscriber.Subscriber.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscriber.js:84:38)
    at MergeMapSubscriber.tryCatcher (/usr/share/kibana/node_modules/rxjs/internal/util/tryCatch.js:7:31)
    at TakeSubscriber.Subscription.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscription.js:50:70)
    at emitWarning (internal/process/promises.js:81:15)
    at emitPromiseRejectionWarnings (internal/process/promises.js:120:9)
    at process._tickCallback (internal/process/next_tick.js:69:34)"},"message":"Error: WebSocket is not open: readyState 3 (CLOSED)
    at WebSocket.send (/usr/share/kibana/node_modules/ws/lib/websocket.js:314:19)
    at Connection.send (/usr/share/kibana/node_modules/puppeteer-core/lib/Connection.js:84:21)
    at gracefullyCloseChrome (/usr/share/kibana/node_modules/puppeteer-core/lib/Launcher.js:191:20)
    at Browser.close (/usr/share/kibana/node_modules/puppeteer-core/lib/Browser.js:208:31)
    at Object.kill (/usr/share/kibana/node_modules/x-pack/plugins/reporting/server/browsers/chromium/driver_factory/index.js:90:25)
    at Subscription.observer.add (/usr/share/kibana/node_modules/x-pack/plugins/reporting/server/browsers/safe_child_process.js:53:18)
    at Subscription.tryCatcher (/usr/share/kibana/node_modules/rxjs/internal/util/tr
May 03 21:40:18 vagrant kibana[7692]: {"type":"error","@timestamp":"2019-05-03T21:40:18Z","tags":["warning","process"],"pid":7692,"level":"error","error":{"message":"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(). (rejection id: 8)","name":"UnhandledPromiseRejectionWarning","stack":"Error: WebSocket is not open: readyState 3 (CLOSED)
    at WebSocket.send (/usr/share/kibana/node_modules/ws/lib/websocket.js:314:19)
    at Connection.send (/usr/share/kibana/node_modules/puppeteer-core/lib/Connection.js:84:21)
    at gracefullyCloseChrome (/usr/share/kibana/node_modules/puppeteer-core/lib/Launcher.js:191:20)
    at Browser.close (/usr/share/kibana/node_modules/puppeteer-core/lib/Browser.js:208:31)
    at Object.kill (/usr/share/kibana/node_modules/x-pack/plugins/reporting/server/browsers/chromium/driver_factory/index.js:90:25)
    at Subscription.observer.add (/usr/share/kibana/node_modules/x-pack/plugins/reporting/server/browsers/safe_child_process.js:53:18)
    at Subscription.tryCatcher (/usr/share/kibana/node_modules/rxjs/internal/util/tryCatch.js:7:31)
    at Subscription.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscription.js:37:59)
    at Subscription.tryCatcher (/usr/share/kibana/node_modules/rxjs/internal/util/tryCatch.js:7:31)
    at InnerSubscriber.Subscription.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscription.js:50:70)
    at InnerSubscriber.Subscriber.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscriber.js:84:38)
    at InnerSubscriber.tryCatcher (/usr/share/kibana/node_modules/rxjs/internal/util/tryCatch.js:7:31)
    at MergeMapSubscriber.Subscription.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscription.js:50:70)
    at MergeMapSubscriber.Subscriber.unsubscribe (/usr/share/kibana/node_modules/rxjs/internal/Subscriber.js:84:38)
    at MergeMapSubscriber.tryCatcher (/usr/share/kibana/node_modules/rxjs/internal/util/tryCat
LeeDr picture LeeDr on 4 May 2019

[SOLVED] (we just need to improve the user experience when this happens)

@joelgriffith walked me through discovering the cause!

Basically, as root on this VM we ran this;

root@vagrant:/var/lib/kibana/headless_shell-linux# ./headless_shell --disable-translate --disable-extensions --disable-background-networking --safebrowsing-disable-auto-update --disable-sync --metrics-recording-only --disable-default-apps --mute-audio --no-first-run --user-data-dir=/tmp/chromium-123 --disable-gpu --no-sandbox --headless --hide-scrollbars --window-size=800,600 --remote-debugging-port=9221 https://localhost:5601

and that output this dump when it exited;

[0507/204855.747054:WARNING:resource_bundle.cc(358)] locale_file_path.empty() for locale
[0507/204855.759643:WARNING:resource_bundle.cc(358)] locale_file_path.empty() for locale
[0507/204855.877548:ERROR:gpu_process_transport_factory.cc(968)] Lost UI shared context.

DevTools listening on ws://127.0.0.1:9221/devtools/browser/669ecd89-fa73-488b-9312-f6d10a5f4eae
[0507/204855.902669:WARNING:resource_bundle.cc(358)] locale_file_path.empty() for locale
[0507/204855.903705:ERROR:egl_util.cc(59)] Failed to load GLES library: /var/lib/kibana/headless_shell-linux/swiftshader/libGLESv2.so: cannot open shared object file: No such file or directory
[0507/204855.928533:ERROR:viz_main_impl.cc(184)] Exiting GPU process due to errors during initialization
[0507/204855.985987:FATAL:nss_util.cc(655)] NSS_VersionCheck("3.26") failed. NSS >= 3.26 is required. Please upgrade to the latest NSS, and if you still get this error, contact your distribution maintainer.
#0 0x000003e962ec <unknown>
#1 0x000003e19e10 <unknown>
#2 0x0000040fdf95 <unknown>

which pointed us to nss_util.cc version problem.

I ran this sudo apt-get install --reinstall libnss3
and that fixed it!

apt list --installed now shows

root@vagrant:/var/lib/kibana/headless_shell-linux# apt list --installed | grep libnss3

WARNING: apt does not have a stable CLI interface. Use with caution in scripts.

libnss3/xenial-updates,xenial-security,now 2:3.28.4-0ubuntu0.16.04.5 amd64 [installed,automatic]
libnss3-nssdb/xenial-updates,xenial-updates,xenial-security,xenial-security,now 2:3.28.4-0ubuntu0.16.04.5 all [installed,automatic]

I reverted my VM to a snapshot before the fix and see the libnss3 versions were
2:3.23 vs the new working version
2:3.28.4;

root@vagrant:~# apt list --installed | grep libnss3

WARNING: apt does not have a stable CLI interface. Use with caution in scripts.

libnss3/now 2:3.23-0ubuntu0.16.04.1 amd64 [installed,upgradable to: 2:3.26.2-0ubuntu0.16.04.2]
libnss3-nssdb/now 2:3.23-0ubuntu0.16.04.1 all [installed,upgradable to: 2:3.26.2-0ubuntu0.16.04.2]

Maybe we could make that newer version a dependency of the .deb package? Or check the version of it on Kibana startup?

LeeDr picture LeeDr on 7 May 2019

Just for my future self: starting Chrome isn't enough since it'll start just fine with missing deps, however it will only error when _navigating_ in cases where libnss3 is outdated/missing.

We should probably try to navigate to kibana (locally) or some well-known address. Might be out of scope, but it appears to be the only way to "sniff" out these types of missing deps.

joelgriffith picture joelgriffith on 10 May 2019
Was this page helpful?
0 / 5 - 0 ratings

Related issues

pkubat picture pkubat  路  75Comments
AlexIoannides picture AlexIoannides  路  138Comments
Alex-Ikanow picture Alex-Ikanow  路  364Comments
Vineeth-Mohan picture Vineeth-Mohan  路  149Comments
rashidkpc picture rashidkpc  路  116Comments