Deadlock in Elastic Search 0.17.4!

Wojciech_Durczynski · August 9, 2011, 10:28am

Hello. I just upgraded from ES 0.16.2 to 0.17.4.
After upgrade my tests started to deadlock ALWAYS.
Below is log from jstack:

Found one Java-level deadlock:

"elasticsearch[index]-pool-182-thread-1":
waiting to lock monitor 0x00007ff3cc007150 (object 0x00007ff44e3755b8, a
java.lang.Object),
which is held by "elasticsearch[Scarlet
Beetle]clusterService#updateTask-pool-191-thread-1"
"elasticsearch[Scarlet Beetle]clusterService#updateTask-pool-191-thread-1":
waiting to lock monitor 0x00007ff3cc0070a8 (object 0x00007ff450110fd0, a
java.lang.Object),
which is held by "elasticsearch[index]-pool-182-thread-1"

Java stack information for the threads listed above:

"elasticsearch[index]-pool-182-thread-1":
at
org.elasticsearch.index.mapper.MapperService$InternalFieldMapperListener.fieldMapper(MapperService.java:710)

waiting to lock <0x00007ff44e3755b8> (a java.lang.Object)
at
org.elasticsearch.index.mapper.DocumentMapper.addFieldMapper(DocumentMapper.java:634)
locked <0x00007ff450110fd0> (a java.lang.Object)
at
org.elasticsearch.index.mapper.object.ObjectMapper$3.fieldMapper(ObjectMapper.java:695)
at
org.elasticsearch.index.mapper.core.AbstractFieldMapper.traverse(AbstractFieldMapper.java:323)
at
org.elasticsearch.index.mapper.object.ObjectMapper.serializeValue(ObjectMapper.java:693)
locked <0x00007ff450110ae0> (a java.lang.Object)
at
org.elasticsearch.index.mapper.object.ObjectMapper.parse(ObjectMapper.java:440)
at
org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:566)
at
org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:490)
at
org.elasticsearch.index.shard.service.InternalIndexShard.prepareIndex(InternalIndexShard.java:289)
at
org.elasticsearch.action.index.TransportIndexAction.shardOperationOnPrimary(TransportIndexAction.java:185)
at
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:428)
at
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:341)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
"elasticsearch[Scarlet Beetle]clusterService#updateTask-pool-191-thread-1":
at
org.elasticsearch.index.mapper.DocumentMapper.addObjectMapperListener(DocumentMapper.java:670)
waiting to lock <0x00007ff450110fd0> (a java.lang.Object)
at org.elasticsearch.index.mapper.MapperService.add(MapperService.java:187)
locked <0x00007ff44e3755b8> (a java.lang.Object)
at org.elasticsearch.index.mapper.MapperService.add(MapperService.java:166)
at
org.elasticsearch.indices.cluster.IndicesClusterStateService.processMapping(IndicesClusterStateService.java:382)
at
org.elasticsearch.indices.cluster.IndicesClusterStateService.applyMappings(IndicesClusterStateService.java:349)
at
org.elasticsearch.indices.cluster.IndicesClusterStateService.clusterChanged(IndicesClusterStateService.java:176)
locked <0x00007ff44dda9ce0> (a java.lang.Object)
at
org.elasticsearch.cluster.service.InternalClusterService$2.run(InternalClusterService.java:254)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)

Found 1 deadlock.

kimchy · August 9, 2011, 10:37am

Can you provide the full thread dump? I only see one thread stack trace
here. Can you please gist it and not paste it into the mail.

2011/8/9 Wojciech Durczyński wojciech.durczynski@comarch.com

Hello. I just upgraded from ES 0.16.2 to 0.17.4.
After upgrade my tests started to deadlock ALWAYS.
Below is log from jstack:

Found one Java-level deadlock:

"elasticsearch[index]-pool-182-thread-1":
waiting to lock monitor 0x00007ff3cc007150 (object 0x00007ff44e3755b8, a
java.lang.Object),
which is held by "elasticsearch[Scarlet
Beetle]clusterService#updateTask-pool-191-thread-1"
"elasticsearch[Scarlet Beetle]clusterService#updateTask-pool-191-thread-1":
waiting to lock monitor 0x00007ff3cc0070a8 (object 0x00007ff450110fd0, a
java.lang.Object),
which is held by "elasticsearch[index]-pool-182-thread-1"

Java stack information for the threads listed above:

"elasticsearch[index]-pool-182-thread-1":
at
org.elasticsearch.index.mapper.MapperService$InternalFieldMapperListener.fieldMapper(MapperService.java:710)

waiting to lock <0x00007ff44e3755b8> (a java.lang.Object)
at
org.elasticsearch.index.mapper.DocumentMapper.addFieldMapper(DocumentMapper.java:634)

locked <0x00007ff450110fd0> (a java.lang.Object)
at
org.elasticsearch.index.mapper.object.ObjectMapper$3.fieldMapper(ObjectMapper.java:695)
at
org.elasticsearch.index.mapper.core.AbstractFieldMapper.traverse(AbstractFieldMapper.java:323)
at
org.elasticsearch.index.mapper.object.ObjectMapper.serializeValue(ObjectMapper.java:693)

locked <0x00007ff450110ae0> (a java.lang.Object)
at
org.elasticsearch.index.mapper.object.ObjectMapper.parse(ObjectMapper.java:440)
at
org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:566)
at
org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:490)
at
org.elasticsearch.index.shard.service.InternalIndexShard.prepareIndex(InternalIndexShard.java:289)
at
org.elasticsearch.action.index.TransportIndexAction.shardOperationOnPrimary(TransportIndexAction.java:185)
at
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:428)
at
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:341)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
"elasticsearch[Scarlet Beetle]clusterService#updateTask-pool-191-thread-1":
at
org.elasticsearch.index.mapper.DocumentMapper.addObjectMapperListener(DocumentMapper.java:670)

waiting to lock <0x00007ff450110fd0> (a java.lang.Object)
at org.elasticsearch.index.mapper.MapperService.add(MapperService.java:187)

locked <0x00007ff44e3755b8> (a java.lang.Object)
at org.elasticsearch.index.mapper.MapperService.add(MapperService.java:166)
at
org.elasticsearch.indices.cluster.IndicesClusterStateService.processMapping(IndicesClusterStateService.java:382)
at
org.elasticsearch.indices.cluster.IndicesClusterStateService.applyMappings(IndicesClusterStateService.java:349)
at
org.elasticsearch.indices.cluster.IndicesClusterStateService.clusterChanged(IndicesClusterStateService.java:176)

locked <0x00007ff44dda9ce0> (a java.lang.Object)
at
org.elasticsearch.cluster.service.InternalClusterService$2.run(InternalClusterService.java:254)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)

Found 1 deadlock.

kimchy · August 9, 2011, 10:40am

Ahh, no need, I see the second thread, lost it in the mail formatting...

On Tue, Aug 9, 2011 at 1:37 PM, Shay Banon kimchy@gmail.com wrote:

Can you provide the full thread dump? I only see one thread stack trace
here. Can you please gist it and not paste it into the mail.

2011/8/9 Wojciech Durczyński wojciech.durczynski@comarch.com

Hello. I just upgraded from ES 0.16.2 to 0.17.4.
After upgrade my tests started to deadlock ALWAYS.
Below is log from jstack:

Found one Java-level deadlock:

"elasticsearch[index]-pool-182-thread-1":
waiting to lock monitor 0x00007ff3cc007150 (object 0x00007ff44e3755b8, a
java.lang.Object),
which is held by "elasticsearch[Scarlet
Beetle]clusterService#updateTask-pool-191-thread-1"
"elasticsearch[Scarlet
Beetle]clusterService#updateTask-pool-191-thread-1":
waiting to lock monitor 0x00007ff3cc0070a8 (object 0x00007ff450110fd0, a
java.lang.Object),
which is held by "elasticsearch[index]-pool-182-thread-1"

Java stack information for the threads listed above:

"elasticsearch[index]-pool-182-thread-1":
at
org.elasticsearch.index.mapper.MapperService$InternalFieldMapperListener.fieldMapper(MapperService.java:710)

waiting to lock <0x00007ff44e3755b8> (a java.lang.Object)
at
org.elasticsearch.index.mapper.DocumentMapper.addFieldMapper(DocumentMapper.java:634)

locked <0x00007ff450110fd0> (a java.lang.Object)
at
org.elasticsearch.index.mapper.object.ObjectMapper$3.fieldMapper(ObjectMapper.java:695)
at
org.elasticsearch.index.mapper.core.AbstractFieldMapper.traverse(AbstractFieldMapper.java:323)
at
org.elasticsearch.index.mapper.object.ObjectMapper.serializeValue(ObjectMapper.java:693)

locked <0x00007ff450110ae0> (a java.lang.Object)
at
org.elasticsearch.index.mapper.object.ObjectMapper.parse(ObjectMapper.java:440)
at
org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:566)
at
org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:490)
at
org.elasticsearch.index.shard.service.InternalIndexShard.prepareIndex(InternalIndexShard.java:289)
at
org.elasticsearch.action.index.TransportIndexAction.shardOperationOnPrimary(TransportIndexAction.java:185)
at
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:428)
at
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:341)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
"elasticsearch[Scarlet
Beetle]clusterService#updateTask-pool-191-thread-1":
at
org.elasticsearch.index.mapper.DocumentMapper.addObjectMapperListener(DocumentMapper.java:670)

waiting to lock <0x00007ff450110fd0> (a java.lang.Object)
at
org.elasticsearch.index.mapper.MapperService.add(MapperService.java:187)

locked <0x00007ff44e3755b8> (a java.lang.Object)
at
org.elasticsearch.index.mapper.MapperService.add(MapperService.java:166)
at
org.elasticsearch.indices.cluster.IndicesClusterStateService.processMapping(IndicesClusterStateService.java:382)
at
org.elasticsearch.indices.cluster.IndicesClusterStateService.applyMappings(IndicesClusterStateService.java:349)
at
org.elasticsearch.indices.cluster.IndicesClusterStateService.clusterChanged(IndicesClusterStateService.java:176)

locked <0x00007ff44dda9ce0> (a java.lang.Object)
at
org.elasticsearch.cluster.service.InternalClusterService$2.run(InternalClusterService.java:254)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)

Found 1 deadlock.

Wojciech_Durczynski · August 9, 2011, 10:44am

If You need stack traces of all threads, here it is:

gist.github.com

https://gist.github.com/Avatah/1133740

jstack.txt

2011-08-09 12:39:17
Full thread dump Java HotSpot(TM) 64-Bit Server VM (16.2-b04 mixed mode):

"Attach Listener" daemon prio=10 tid=0x00007f5468007000 nid=0x5125 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"elasticsearch[merge]-pool-184-thread-1" daemon prio=10 tid=0x00007f5464c6c000 nid=0x50c3 waiting on condition [0x00007f546cc38000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00007f54c4783b78> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)

This file has been truncated. show original

kimchy · August 9, 2011, 11:27am

Can you open an issue for this while I work on a fix. Its been there in
previous versions, its just a matter of timing and order. Small chances for
it to happen, but it needs to be fixed.

2011/8/9 Wojciech Durczyński wojciech.durczynski@comarch.com

If You need stack traces of all threads, here it is:
Deadlock in ES 0.17.4 · GitHub

Wojciech_Durczynski · August 9, 2011, 12:26pm

Issue created: https://github.com/elasticsearch/elasticsearch/issues/1221

kimchy · August 9, 2011, 12:27pm

Argh :), already created an issue:
Rare deadlock when introducing new mapping fields/objects · Issue #1222 · elastic/elasticsearch · GitHub since I have the
fix ready, will point your issue to the other one...

2011/8/9 Wojciech Durczyński wojciech.durczynski@comarch.com

Issue created: Deadlock in Elastic Search 0.17.4 · Issue #1221 · elastic/elasticsearch · GitHub

Wojciech_Durczynski · August 9, 2011, 12:55pm

Thank You.
Do you plan to release version 0.17.5 with this fix? When?

kimchy · August 9, 2011, 2:26pm

Yes, it has been applied to 0.17 branch and will be part of 0.17.5. It will
be released in a few days.

2011/8/9 Wojciech Durczyński wojciech.durczynski@comarch.com

Thank You.
Do you plan to release version 0.17.5 with this fix? When?