Failed to deserialize response of type org.elasticsearch.xpack.action.XPackUsageResponse

Elastic Stack Kibana
1

I installed a new license yesterday. Things were working great. This morning, I restarted my master node. Things seem OK from a curl perspective. I can do stuff. Authentication is working.

Kibana however, is not happy:

{ 
   "type": "log",
   "@timestamp": "2016-08-26T15:25:45Z",
   "tags": ["status","plugin:security@5.0.0-alpha5-SNAPSHOT","error"],
   "pid": 35839,
   "state": "red",
   "message": "Status changed from red to red - Service Unavailable",
   "prevState":"red",
   "prevMsg": "[transport_serialization_exception] Failed to deserialize response of type [org.elasticsearch.xpack.action.XPackUsageResponse]"
}

And the web page has

Login is currently disabled because the license could not be determined.
Please check that Elasticsearch is running, then refresh this page.

So... yeah... any suggestions?

Thanks!

2

Found another log event:

[2016-08-26 14:51:20,169][WARN ][rest.suppressed          ] path: _xpack/usage, params: {}
RemoteTransportException[[Failed to deserialize response of type [org.elasticsearch.xpack.action.XPackUsageResponse]]]; nested: TransportSerializationException[Failed to deserialize response of type [org.elasticsearch.xpack.action.XPackUsageResponse]]; nested: ClassCastException[java.lang.Double cannot be cast to java.util.Map];
Caused by: TransportSerializationException[Failed to deserialize response of type [org.elasticsearch.xpack.action.XPackUsageResponse]]; nested: ClassCastException[java.lang.Double cannot be cast to java.util.Map];
	at org.elasticsearch.transport.TcpTransport.handleResponse(TcpTransport.java:1234)
	at org.elasticsearch.transport.TcpTransport.messageReceived(TcpTransport.java:1206)
	at org.elasticsearch.transport.netty4.Netty4MessageChannelHandler.channelRead(Netty4MessageChannelHandler.java:74)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:372)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:358)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:350)
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:293)
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:280)
	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:396)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:248)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:372)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:358)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:350)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1334)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:372)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:358)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:926)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:129)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:571)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysPlain(NioEventLoop.java:474)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:428)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:398)
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:877)
	at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.ClassCastException: java.lang.Double cannot be cast to java.util.Map
	at org.elasticsearch.common.io.stream.StreamInput.readMap(StreamInput.java:437)
	at org.elasticsearch.xpack.security.SecurityFeatureSet$Usage.<init>(SecurityFeatureSet.java:172)
	at org.elasticsearch.common.io.stream.NamedWriteableAwareStreamInput.readNamedWriteable(NamedWriteableAwareStreamInput.java:40)
	at org.elasticsearch.xpack.action.XPackUsageResponse.readFrom(XPackUsageResponse.java:60)
	at org.elasticsearch.transport.TcpTransport.handleResponse(TcpTransport.java:1231)
	... 23 more
3

Hey Dave,

What does the response from /_xpack/license look like?

Are you seeing any errors or warnings in your Kibana logs?

4

Hey Tyler! (I XXX'd our organization so I don't have to stop ask for permission to type it :slight_smile: )

$ curl -s -XGET elastic:changeme@localhost:9205/_xpack/license?pretty
{
  "license" : {
    "status" : "active",
    "uid" : "b925c19f-ce62-4851-b95a-6f0efec26fee",
    "type" : "trial",
    "issue_date" : "2016-08-25T00:00:00.000Z",
    "issue_date_in_millis" : 1472083200000,
    "expiry_date" : "2016-09-27T23:59:59.999Z",
    "expiry_date_in_millis" : 1475020799999,
    "max_nodes" : 15,
    "issued_to" : "XXX",
    "issuer" : "Aunik Bhattacharjee"
  }
}
5

There's this...

{
    "@timestamp": "2016-08-29T14:45:23Z",
    "message": "GET /api/xpack/v1/info 404 3ms - 9.0B",
    "method": "get",
    "pid": 29898,
    "req": {
        "headers": {
            "accept": "application/json, text/plain, */*",
            "accept-encoding": "gzip, deflate, sdch, br",
            "accept-language": "en-US,en;q=0.8",
            "connection": "Keep-Alive",
            "host": "127.0.0.1:5602",
            "kbn-version": "5.0.0-alpha5",
            "referer": "https://foo.com/kibana_v5/login?next=%2F",
            "user-agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/52.0.2743.116 Safari/537.36",
            "x-forwarded-for": "192.168.0.1",
            "x-forwarded-host": "foo.com",
            "x-forwarded-server": "foo.com"
        },
        "method": "get",
        "referer": "https://foo.com/kibana_v5/login?next=%2F",
        "remoteAddress": "127.0.0.1",
        "url": "/api/xpack/v1/info",
        "userAgent": "127.0.0.1"
    },
    "res": {
        "contentLength": 9,
        "responseTime": 3,
        "statusCode": 404
    },
    "statusCode": 404,
    "tags": [],
    "type": "response"
}

Everything else is status 200 or 304. When I hit that with curl I don't get a 404.

$ curl -vs -XGET elastic:changeme@localhost:5602/api/xpack/v1/info       
* About to connect() to localhost port 5602 (#0)
*   Trying 127.0.0.1... connected
* Connected to localhost (127.0.0.1) port 5602 (#0)
* Server auth using Basic with user 'elastic'
> GET /api/xpack/v1/info HTTP/1.1
> Authorization: Basic ZWxhc3RpYzpjaGFuZ2VtZQ==
> User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.19.1 Basic ECC zlib/1.2.3 libidn/1.18 libssh2/1.4.2
> Host: localhost:5602
> Accept: */*
> 
< HTTP/1.1 200 OK
< content-type: text/html; charset=utf-8
< kbn-name: kibana
< kbn-version: 5.0.0-alpha5
< set-cookie: sid=Fe26.2**8af22d60d7dfa515655d4d746c27f544dc141d2a38eb0eccd0fdd8011f711695*E3q5RWeAzQD8xxbL_l8Oag*XBNlsN-DGNUOEIyl4iuzwQJilgsTAAC5u_1uR-1NgNuYNx1hx4lPAD5UuLQp3DdL01SDNrceIFsq9sx2uQke0tb0M_ecwxaW9OJpTXmz3E0**ecb3b8da3283fd1996e8ec5ffd4c34581de8aa279cc7c78c4ab5a6635543a08a*O3UDxRz1NYSwLmNZzdvlYyBDj07b2r6Qlwrv0iBj06w; HttpOnly; Path=/kibana_v5/
< cache-control: no-cache
< content-length: 119
< accept-ranges: bytes
< Date: Mon, 29 Aug 2016 14:54:58 GMT
< Connection: keep-alive
< 
<html>
<head><script type="text/javascript">window.location.reload();</script></head>
<body>reloading...</body>
* Connection #0 to host localhost left intact
* Closing connection #0
</html>

Oh, but if I leave off the authentication, I get:

$ curl -vs -XGET 127.0.0.1:5602/api/xpack/v1/info
* About to connect() to 127.0.0.1 port 5602 (#0)
*   Trying 127.0.0.1... connected
* Connected to 127.0.0.1 (127.0.0.1) port 5602 (#0)
> GET /api/xpack/v1/info HTTP/1.1
> User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.19.1 Basic ECC zlib/1.2.3 libidn/1.18 libssh2/1.4.2
> Host: 127.0.0.1:5602
> Accept: */*
> 
< HTTP/1.1 404 Not Found
< kbn-name: kibana
< kbn-version: 5.0.0-alpha5
< content-type: application/json; charset=utf-8
< cache-control: no-cache
< content-length: 38
< Date: Mon, 29 Aug 2016 15:00:36 GMT
< Connection: keep-alive
< 
* Connection #0 to host 127.0.0.1 left intact
* Closing connection #0
{"statusCode":404,"error":"Not Found"}

Is this a chicken and egg type problem? Kibana is loading the login page, but blocks out the username/password because it can't find the license info, which it can't get unless you log in? Catch-22?

Thanks

6

Looks like it's not chicken and egg, catch 22. The "failed to deserialize" comes after the license expiry check.

Here's some Kibana logs:

{"type":"log","@timestamp":"2016-08-26T18:51:15Z","tags":["status","plugin:markdown_vis@5.0.0-alpha5","info"],"pid":29898,"state":"green","message":"Status changed from uninitialized to green - Ready","prevState":"uninitialized","prevMsg":"uninitialized"}
{"type":"log","@timestamp":"2016-08-26T18:51:15Z","tags":["license","info","xpack"],"pid":29898,"message":"Imported license information from Elasticsearch: mode: trial | status: active | expiry date: 2016-09-27T19:59:59-04:00"}
{"type":"log","@timestamp":"2016-08-26T18:51:15Z","tags":["status","plugin:metric_vis@5.0.0-alpha5","info"],"pid":29898,"state":"green","message":"Status changed from uninitialized to green - Ready","prevState":"uninitialized","prevMsg":"uninitialized"}
{"type":"log","@timestamp":"2016-08-26T18:51:15Z","tags":["status","plugin:spy_modes@5.0.0-alpha5","info"],"pid":29898,"state":"green","message":"Status changed from uninitialized to green - Ready","prevState":"uninitialized","prevMsg":"uninitialized"}
{"type":"log","@timestamp":"2016-08-26T18:51:15Z","tags":["status","plugin:status_page@5.0.0-alpha5","info"],"pid":29898,"state":"green","message":"Status changed from uninitialized to green - Ready","prevState":"uninitialized","prevMsg":"uninitialized"}
{"type":"log","@timestamp":"2016-08-26T18:51:15Z","tags":["status","plugin:table_vis@5.0.0-alpha5","info"],"pid":29898,"state":"green","message":"Status changed from uninitialized to green - Ready","prevState":"uninitialized","prevMsg":"uninitialized"}
{"type":"log","@timestamp":"2016-08-26T18:51:15Z","tags":["listening","info"],"pid":29898,"message":"Server running at http://127.0.0.1:5602"}
{"type":"log","@timestamp":"2016-08-26T18:51:15Z","tags":["status","ui settings","info"],"pid":29898,"state":"green","message":"Status changed from uninitialized to green - Ready","prevState":"uninitialized","prevMsg":"uninitialized"}
{"type":"log","@timestamp":"2016-08-26T18:51:15Z","tags":["status","plugin:xpack_main@5.0.0-alpha5-SNAPSHOT","error"],"pid":29898,"state":"red","message":"Status changed from yellow to red - [transport_serialization_exception] Failed to deserialize response of type [org.elasticsearch.xpack.action.XPackUsageResponse]","prevState":"yellow","prevMsg":"Waiting for Elasticsearch"}
{"type":"log","@timestamp":"2016-08-26T18:51:15Z","tags":["status","plugin:graph@5.0.0-alpha5-SNAPSHOT","error"],"pid":29898,"state":"red","message":"Status changed from yellow to red - [transport_serialization_exception] Failed to deserialize response of type [org.elasticsearch.xpack.action.XPackUsageResponse]","prevState":"yellow","prevMsg":"Waiting for Elasticsearch"}
{"type":"log","@timestamp":"2016-08-26T18:51:15Z","tags":["status","plugin:reporting@5.0.0-alpha5-SNAPSHOT","error"],"pid":29898,"state":"red","message":"Status changed from yellow to red - [transport_serialization_exception] Failed to deserialize response of type [org.elasticsearch.xpack.action.XPackUsageResponse]","prevState":"yellow","prevMsg":"Waiting for Elasticsearch"}
{"type":"log","@timestamp":"2016-08-26T18:51:15Z","tags":["status","plugin:security@5.0.0-alpha5-SNAPSHOT","error"],"pid":29898,"state":"red","message":"Status changed from yellow to red - [transport_serialization_exception] Failed to deserialize response of type [org.elasticsearch.xpack.action.XPackUsageResponse]","prevState":"yellow","prevMsg":"Waiting for Elasticsearch"}
{"type":"log","@timestamp":"2016-08-26T18:51:17Z","tags":["status","plugin:monitoring@5.0.0-alpha5-SNAPSHOT","error"],"pid":29898,"state":"red","message":"Status changed from green to red - Service Unavailable","prevState":"green","prevMsg":"Ready"}
{"type":"log","@timestamp":"2016-08-26T18:51:17Z","tags":["status","plugin:xpack_main@5.0.0-alpha5-SNAPSHOT","error"],"pid":29898,"state":"red","message":"Status changed from red to red - Service Unavailable","prevState":"red","prevMsg":"[transport_serialization_exception] Failed to deserialize response of type [org.elasticsearch.xpack.action.XPackUsageResponse]"}
{"type":"log","@timestamp":"2016-08-26T18:51:17Z","tags":["status","plugin:graph@5.0.0-alpha5-SNAPSHOT","error"],"pid":29898,"state":"red","message":"Status changed from red to red - Service Unavailable","prevState":"red","prevMsg":"[transport_serialization_exception] Failed to deserialize response of type [org.elasticsearch.xpack.action.XPackUsageResponse]"}
{"type":"log","@timestamp":"2016-08-26T18:51:17Z","tags":["status","plugin:reporting@5.0.0-alpha5-SNAPSHOT","error"],"pid":29898,"state":"red","message":"Status changed from red to red - Service Unavailable","prevState":"red","prevMsg":"[transport_serialization_exception] Failed to deserialize response of type [org.elasticsearch.xpack.action.XPackUsageResponse]"}
7

Dave -
This is a confirmed bug with the fix in Beta1. The workaround is to point Kibana at the elected Master.