search

elastic / elasticsearch

Free and Open Source, Distributed, RESTful Search Engine
https://www.elastic.co/products/elasticsearch
Other
1.16k stars 24.84k forks source link

Inconsistent behavior and error messaging between bulk update and bulk index requests #9379

Open nellicus opened 9 years ago

nellicus commented 9 years ago

2 bulk requests one doing update, one doing insert, behave incosistently:

tony@w530 ~ $ cat bulk-index.txt 
{ "index" : { "_index": "test-index", "_type": "test-type", "_id": "1"} }
{ "foo": "b\ar" }
{ "index" : { "_index": "test-index", "_type": "test-type", "_id": "1"} }
{ "foo": "bar" }

tony@w530 ~ $ cat bulk-update.txt 
{ "update" : { "_index": "test-index", "_type": "test-type", "_id": "1"} }
{ "doc": {  "foo": "b\ar" }}
{ "update" : { "_index": "test-index", "_type": "test-type", "_id": "1"} }
{ "doc": {  "foo": "bar" }}

1) bulk-index.txt: requests fail or succeed individually, for the failing ones a related stacktrace is printed in logs

tony@w530 ~ $ curl -s -XPOST localhost:9200/_bulk?pretty --data-binary @bulk-index.txt
{
  "took" : 6,
  "errors" : true,
  "items" : [ {
    "index" : {
      "_index" : "test-index",
      "_type" : "test-type",
      "_id" : "1",
      "status" : 400,
      "error" : "MapperParsingException[failed to parse [foo]]; nested: JsonParseException[Unrecognized character escape 'a' (code 97)\n at [Source: [B@5ae957f1; line: 1, column: 14]]; "
    }
  }, {
    "index" : {
      "_index" : "test-index",
      "_type" : "test-type",
      "_id" : "1",
      "_version" : 4,
      "status" : 200
    }
  } ]
}

In logs:

[2015-01-21 17:40:04,708][DEBUG][action.bulk              ] [nodeD2] [test-index][2] failed to execute bulk item (index) index {[test-index][test-type][1], source[{ "foo": "b\ar" }^M]}
org.elasticsearch.index.mapper.MapperParsingException: failed to parse [foo]
        at org.elasticsearch.index.mapper.core.AbstractFieldMapper.parse(AbstractFieldMapper.java:415)
        at org.elasticsearch.index.mapper.object.ObjectMapper.serializeValue(ObjectMapper.java:707)
        at org.elasticsearch.index.mapper.object.ObjectMapper.parse(ObjectMapper.java:500)
        at org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:541)
        at org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:490)
        at org.elasticsearch.index.shard.service.InternalIndexShard.prepareIndex(InternalIndexShard.java:413)
        at org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:435)
        at org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:150)
        at org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:511)
        at org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:419)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:745)
Caused by: org.elasticsearch.common.jackson.core.JsonParseException: Unrecognized character escape 'a' (code 97)
 at [Source: [B@5bcacee; line: 1, column: 14]
        at org.elasticsearch.common.jackson.core.JsonParser._constructError(JsonParser.java:1419)
        at org.elasticsearch.common.jackson.core.base.ParserMinimalBase._reportError(ParserMinimalBase.java:508)
        at org.elasticsearch.common.jackson.core.base.ParserMinimalBase._handleUnrecognizedCharacterEscape(ParserMinimalBase.java:485)
        at org.elasticsearch.common.jackson.core.json.UTF8StreamJsonParser._decodeEscaped(UTF8StreamJsonParser.java:2924)
        at org.elasticsearch.common.jackson.core.json.UTF8StreamJsonParser._finishString2(UTF8StreamJsonParser.java:2209)
        at org.elasticsearch.common.jackson.core.json.UTF8StreamJsonParser._finishString(UTF8StreamJsonParser.java:2165)
        at org.elasticsearch.common.jackson.core.json.UTF8StreamJsonParser.getText(UTF8StreamJsonParser.java:279)
        at org.elasticsearch.common.xcontent.json.JsonXContentParser.text(JsonXContentParser.java:86)
        at org.elasticsearch.common.xcontent.support.AbstractXContentParser.textOrNull(AbstractXContentParser.java:194)
        at org.elasticsearch.index.mapper.core.StringFieldMapper.parseCreateFieldForString(StringFieldMapper.java:337)
        at org.elasticsearch.index.mapper.core.StringFieldMapper.parseCreateField(StringFieldMapper.java:277)
        at org.elasticsearch.index.mapper.core.AbstractFieldMapper.parse(AbstractFieldMapper.java:405)
        ... 12 more

2) bulk-update.txt: entire request fails, no stacktrace in the logs

curl -s -XPOST localhost:9200/_bulk?pretty --data-binary @bulk-update.txt 
{
  "error" : "JsonParseException[Unrecognized character escape 'a' (code 97)\n at [Source: [B@cb1ae5d; line: 1, column: 24]]",
  "status" : 500
}

No exception printed in logs

olcbean commented 7 years ago

@nellicus @cbuescher is this issue still active?

I am not able to reproduce it : in master (6.0) both _bulk requests result in the same REST error

{
  "error": "Content-Type header [text/plain] is not supported",
  "status": 406
}

The error msg is misleading (perhaps and improvement is in order), but at least consistent ;)

jasontedor commented 7 years ago

@olcbean That's because you have to send a Content-Type header of application/x-ndjson for bulk requests, not text/plain as you appear to have done here. And yes, this issue is still active.

olcbean commented 7 years ago

@jasontedor Right. With the Content-Type mismatch out of the way, this seems to depend on deciding https://github.com/elastic/elasticsearch/issues/24319#issuecomment-297138123. Correct?

verkhovin commented 5 years ago

I have investigated the issue a little. Exception on bulk update occurs at org.elasticsearch.common.xcontent.ObjectParser:386 The full stack trace: 

[elasticsearch] org.elasticsearch.common.xcontent.XContentParseException: [1:20] [UpdateRequest] failed to parse field [doc]
[elasticsearch]     at org.elasticsearch.common.xcontent.ObjectParser.parseValue(ObjectParser.java:386)
[elasticsearch]     at org.elasticsearch.common.xcontent.ObjectParser.parseSub(ObjectParser.java:396)
[elasticsearch]     at org.elasticsearch.common.xcontent.ObjectParser.parse(ObjectParser.java:238)
[elasticsearch]     at org.elasticsearch.action.update.UpdateRequest.fromXContent(UpdateRequest.java:833)
[elasticsearch]     at org.elasticsearch.action.bulk.BulkRequestParser.parse(BulkRequestParser.java:290)
[elasticsearch]     at org.elasticsearch.action.bulk.BulkRequest.add(BulkRequest.java:304)
[elasticsearch]     at org.elasticsearch.rest.action.document.RestBulkAction.prepareRequest(RestBulkAction.java:96)
[elasticsearch]     at org.elasticsearch.rest.BaseRestHandler.handleRequest(BaseRestHandler.java:87)
[elasticsearch]     at org.elasticsearch.xpack.security.rest.SecurityRestFilter.lambda$handleRequest$0(SecurityRestFilter.java:58)
[elasticsearch]     at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:63)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.lambda$writeAuthToContext$24(AuthenticationService.java:570)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.writeAuthToContext(AuthenticationService.java:579)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.finishAuthentication(AuthenticationService.java:560)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.consumeUser(AuthenticationService.java:510)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.lambda$consumeToken$16(AuthenticationService.java:404)
[elasticsearch]     at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:63)
[elasticsearch]     at org.elasticsearch.action.support.ContextPreservingActionListener.onResponse(ContextPreservingActionListener.java:43)
[elasticsearch]     at org.elasticsearch.xpack.core.common.IteratingActionListener.onResponse(IteratingActionListener.java:120)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.lambda$consumeToken$13(AuthenticationService.java:374)
[elasticsearch]     at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:63)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.support.CachingUsernamePasswordRealm.lambda$authenticateWithCache$1(CachingUsernamePasswordRealm.java:145)
[elasticsearch]     at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:63)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.support.CachingUsernamePasswordRealm.handleCachedAuthentication(CachingUsernamePasswordRealm.java:196)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.support.CachingUsernamePasswordRealm.lambda$authenticateWithCache$2(CachingUsernamePasswordRealm.java:137)
[elasticsearch]     at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:63)
[elasticsearch]     at org.elasticsearch.common.util.concurrent.ListenableFuture$1.doRun(ListenableFuture.java:99)
[elasticsearch]     at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)
[elasticsearch]     at org.elasticsearch.common.util.concurrent.EsExecutors$DirectExecutorService.execute(EsExecutors.java:196)
[elasticsearch]     at org.elasticsearch.common.util.concurrent.ListenableFuture.notifyListener(ListenableFuture.java:93)
[elasticsearch]     at org.elasticsearch.common.util.concurrent.ListenableFuture.addListener(ListenableFuture.java:55)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.support.CachingUsernamePasswordRealm.authenticateWithCache(CachingUsernamePasswordRealm.java:132)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.support.CachingUsernamePasswordRealm.authenticate(CachingUsernamePasswordRealm.java:103)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.lambda$consumeToken$15(AuthenticationService.java:365)
[elasticsearch]     at org.elasticsearch.xpack.core.common.IteratingActionListener.run(IteratingActionListener.java:102)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.consumeToken(AuthenticationService.java:408)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.lambda$extractToken$11(AuthenticationService.java:335)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.extractToken(AuthenticationService.java:345)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.lambda$checkForApiKey$3(AuthenticationService.java:288)
[elasticsearch]     at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:63)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.ApiKeyService.authenticateWithApiKeyIfPresent(ApiKeyService.java:358)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.checkForApiKey(AuthenticationService.java:269)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.lambda$authenticateAsync$0(AuthenticationService.java:252)
[elasticsearch]     at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:63)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.TokenService.getAndValidateToken(TokenService.java:390)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.lambda$authenticateAsync$2(AuthenticationService.java:248)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.lambda$lookForExistingAuthentication$6(AuthenticationService.java:306)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.lookForExistingAuthentication(AuthenticationService.java:317)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.authenticateAsync(AuthenticationService.java:244)
[elasticsearch]     at org.elasticsearch.xpack.security.authc.AuthenticationService.authenticate(AuthenticationService.java:122)
[elasticsearch]     at org.elasticsearch.xpack.security.rest.SecurityRestFilter.handleRequest(SecurityRestFilter.java:55)
[elasticsearch]     at org.elasticsearch.rest.RestController.dispatchRequest(RestController.java:220)
[elasticsearch]     at org.elasticsearch.rest.RestController.tryAllHandlers(RestController.java:293)
[elasticsearch]     at org.elasticsearch.rest.RestController.dispatchRequest(RestController.java:164)
[elasticsearch]     at org.elasticsearch.http.AbstractHttpServerTransport.dispatchRequest(AbstractHttpServerTransport.java:322)
[elasticsearch]     at org.elasticsearch.http.AbstractHttpServerTransport.handleIncomingRequest(AbstractHttpServerTransport.java:372)
[elasticsearch]     at org.elasticsearch.http.AbstractHttpServerTransport.incomingRequest(AbstractHttpServerTransport.java:301)
[elasticsearch]     at org.elasticsearch.http.netty4.Netty4HttpRequestHandler.channelRead0(Netty4HttpRequestHandler.java:69)
[elasticsearch]     at org.elasticsearch.http.netty4.Netty4HttpRequestHandler.channelRead0(Netty4HttpRequestHandler.java:31)
[elasticsearch]     at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352)
[elasticsearch]     at org.elasticsearch.http.netty4.Netty4HttpPipeliningHandler.channelRead(Netty4HttpPipeliningHandler.java:58)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352)
[elasticsearch]     at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
[elasticsearch]     at io.netty.handler.codec.MessageToMessageCodec.channelRead(MessageToMessageCodec.java:111)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352)
[elasticsearch]     at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352)
[elasticsearch]     at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352)
[elasticsearch]     at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:328)
[elasticsearch]     at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:302)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352)
[elasticsearch]     at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:287)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352)
[elasticsearch]     at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1421)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
[elasticsearch]     at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
[elasticsearch]     at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:930)
[elasticsearch]     at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
[elasticsearch]     at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:697)
[elasticsearch]     at io.netty.channel.nio.NioEventLoop.processSelectedKeysPlain(NioEventLoop.java:597)
[elasticsearch]     at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:551)
[elasticsearch]     at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:511)
[elasticsearch]     at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:918)
[elasticsearch]     at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
[elasticsearch]     at java.base/java.lang.Thread.run(Thread.java:830)
[elasticsearch] Caused by: com.fasterxml.jackson.core.JsonParseException: Unrecognized character escape 'a' (code 97)
[elasticsearch]  at [Source: org.elasticsearch.transport.netty4.ByteBufStreamInput@636d8d09; line: 1, column: 24]
[elasticsearch]     at com.fasterxml.jackson.core.JsonParser._constructError(JsonParser.java:1702)
[elasticsearch]     at com.fasterxml.jackson.core.base.ParserMinimalBase._reportError(ParserMinimalBase.java:558)
[elasticsearch]     at com.fasterxml.jackson.core.base.ParserMinimalBase._handleUnrecognizedCharacterEscape(ParserMinimalBase.java:535)
[elasticsearch]     at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._decodeEscaped(UTF8StreamJsonParser.java:3247)
[elasticsearch]     at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._finishString2(UTF8StreamJsonParser.java:2514)
[elasticsearch]     at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._finishString(UTF8StreamJsonParser.java:2436)
[elasticsearch]     at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.getTextCharacters(UTF8StreamJsonParser.java:467)
[elasticsearch]     at com.fasterxml.jackson.core.JsonGenerator.copyCurrentEvent(JsonGenerator.java:1720)
[elasticsearch]     at com.fasterxml.jackson.core.JsonGenerator.copyCurrentStructure(JsonGenerator.java:1826)
[elasticsearch]     at com.fasterxml.jackson.core.JsonGenerator.copyCurrentStructure(JsonGenerator.java:1814)
[elasticsearch]     at org.elasticsearch.common.xcontent.json.JsonXContentGenerator.copyCurrentStructure(JsonXContentGenerator.java:418)
[elasticsearch]     at org.elasticsearch.common.xcontent.XContentBuilder.copyCurrentStructure(XContentBuilder.java:988)
[elasticsearch]     at org.elasticsearch.action.update.UpdateRequest.lambda$static$5(UpdateRequest.java:87)
[elasticsearch]     at org.elasticsearch.common.xcontent.AbstractObjectParser.lambda$declareObject$1(AbstractObjectParser.java:146)
[elasticsearch]     at org.elasticsearch.common.xcontent.ObjectParser.lambda$declareField$4(ObjectParser.java:283)
[elasticsearch]     at org.elasticsearch.common.xcontent.ObjectParser.parseValue(ObjectParser.java:384)
[elasticsearch]     ... 99 more

The error occurs because in case of bulk update we try to parse update request source before it actually will be sent to execute by NodeClient (refer to BulkRequestParser#parse():287 and below). I don't understand what is purpose.

For index bulk request in the other hand, the request source is not parsed on this level (refer to BulkRequestParser#parse():262 , but is parsed much later (refer to TransportShardBulkAction#executeBulkItemRequest()). There errors for individual requests are wrapped to Engine.IndexResult.

So update and index request handling are inconsistent. I'm not good enough in the project's code to fix this behavior by myself, as it looks too hard for the first issue (or not?). It seems index and update requests should be handled in the same (consistent) way. Errors should be handled on an another level and should be wrapped into something like Engine.UpdateResult (but we have no such class).

Correct me please, if I am wrong.

Razi007 commented 4 years ago

Interested to work here if this issue is still active

timothy-choi commented 1 year ago

If this issue is still open, I would like to work on it.

vishv843 commented 5 months ago

I would like to work on this issue