[Benchmarking Result] ES 0.90.3 took much longer for indexing than ES 0.20.6 ( GC problem? )


(Munna) #1

Summary:

Apologize at the beginning for this long post but thought it's worth sharing the result. I did a benchmarking for the indexing time using Elasticsearch 0.90.3 version and compared that to 0.20.6 version. Surprisingly ES 0.90.3 performed worse than ES 0.20.6 version. Elasticsearch has a nice API to look into index operation stats (curl "localhost:9200/_nodes/stats?all=true") which I used to find out the reason and found that Garbage Collection ran much much longer in ES 0.90.3 than ES 0.20.6 ( hours vs minutes). I am not sure whether this is the only reason for ES 0.90.3 to perform worse than the previous version. So, I am seeking experts help here providing the experiment detail for the two experiments I carried out. If required I am willing to share the bulk operations we do against Elasticsearch. Thank you in advance for your thoughts/suggestions/questions.

My Questions to this forum are:

(1) Why does GC in ES 0.90.3 take longer than ES 0.20.6 version having the same JVM setting?
(2) What can we do to improve GC time in ES 0.90.3
(3) Are there any other configurations required to improve indexing time in ES 0.90.3 ( I know this is not a specific question but interested to know the suggestions)

==================================================================================================================
Experiment 1: All settings are absolutely same for both ES version clusters except increased threadpool size and queue_size in ES 0.90.3 version
==================================================================================================================

DataSize: 500K documents
Total Size: 658 MB (approx)
ES Cluster Size: 3 nodes (AWS EC2 m2.xlarge instance (Memory 17.1 GB, Compute Units: 6))

of Index : 7

of shards for each index: 6

of replicas for each shard: 1

JVM (oracle 1.7.0_13 ) settings:
============

wrapper.java.additional.1=-Delasticsearch-service
wrapper.java.additional.2=-Des.path.home=%ES_HOME%
wrapper.java.additional.3=-Xss256k
wrapper.java.additional.4=-XX:+UseParNewGC
wrapper.java.additional.5=-XX:+UseConcMarkSweepGC
wrapper.java.additional.6=-XX:CMSInitiatingOccupancyFraction=75
wrapper.java.additional.7=-XX:+UseCMSInitiatingOccupancyOnly
wrapper.java.additional.8=-XX:+HeapDumpOnOutOfMemoryError
wrapper.java.additional.9=-Djava.awt.headless=true
wrapper.java.additional.10=-XX:MaxPermSize=1024m
wrapper.java.additional.11=-Des.max-open-files=true

Initial Java Heap Size (in MB)

wrapper.java.initmemory=8192

Maximum Java Heap Size (in MB)

wrapper.java.maxmemory=8192

Indexing time:
==============

ES 0.20.6 : 4 hrs 57 minutes (approx)
ES 0.90.3 : 6 hrs 12 minutes (approx)

Index Stat (providing info of just one node from the clusters of each version)
============================================================

ES 0.20.6:
========

{
"cluster_name": "xxxxxxxxx",
"nodes": {
"-j6dAUBySuuDU-nKt7Fyrw": {
"fs": {
"data": [
{
"available": "407.7gb",
"available_in_bytes": 437794705408,
"dev": "/dev/xvdb",
"disk_read_size": "1.5mb",
"disk_read_size_in_bytes": 1627648,
"disk_reads": 437,
"disk_write_size": "68.1gb",
"disk_write_size_in_bytes": 73151741440,
"disk_writes": 1832827,
"free": "407.7gb",
"total": "409.7gb",
"total_in_bytes": 439983034368
}
],
"timestamp": 1378496996333
},
"hostname": "xxxxxxxxxxx",
"http": {
"current_open": 4,
"total_opened": 22243
},
"indices": {
"cache": {
"bloom_size": "0b",
"bloom_size_in_bytes": 0,
"field_evictions": 0,
"field_size": "0b",
"field_size_in_bytes": 0,
"filter_count": 0,
"filter_evictions": 0,
"filter_size": "0b",
"filter_size_in_bytes": 0,
"id_cache_size": "0b",
"id_cache_size_in_bytes": 0
},
"docs": {
"count": 430122,
"deleted": 43501
},
"flush": {
"total": 1140,
"total_time": "3.6m",
"total_time_in_millis": 219575
},
"get": {
"current": 0,
"exists_time": "6.8m",
"exists_time_in_millis": 411873,
"exists_total": 449999,
"missing_time": "3.6m",
"missing_time_in_millis": 218845,
"missing_total": 311984,
"time": "10.5m",
"time_in_millis": 630718,
"total": 761983
},
"indexing": {
"delete_current": 0,
"delete_time": "0s",
"delete_time_in_millis": 0,
"delete_total": 0,
"index_current": 0,
"index_time": "2.3h",
"index_time_in_millis": 8457005,
"index_total": 557055
},
"merges": {
"current": 0,
"current_docs": 0,
"current_size": "0b",
"current_size_in_bytes": 0,
"total": 0,
"total_docs": 0,
"total_size": "0b",
"total_size_in_bytes": 0,
"total_time": "0s",
"total_time_in_millis": 0
},
"refresh": {
"total": 828303,
"total_time": "1d",
"total_time_in_millis": 94763236
},
"search": {
"fetch_current": 0,
"fetch_time": "7m",
"fetch_time_in_millis": 425956,
"fetch_total": 142283,
"query_current": 0,
"query_time": "1d",
"query_time_in_millis": 91201118,
"query_total": 24950295
},
"store": {
"size": "1.9gb",
"size_in_bytes": 2097636533,
"throttle_time": "0s",
"throttle_time_in_millis": 0
}
},
"jvm": {
"buffer_pools": {
"direct": {
"count": 722,
"total_capacity": "24.1mb",
"total_capacity_in_bytes": 25301460,
"used": "24.1mb",
"used_in_bytes": 25301460
},
"mapped": {
"count": 0,
"total_capacity": "0b",
"total_capacity_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
}
},
"gc": {
"collection_count": 20556,
"collection_time": "47 minutes, 30 seconds and 759 milliseconds",
"collection_time_in_millis": 2850759,
"collectors": {
"ConcurrentMarkSweep": {
"collection_count": 37,
"collection_time": "3 minutes, 17 seconds and 858 milliseconds",
"collection_time_in_millis": 197858
},
"ParNew": {
"collection_count": 20519,
"collection_time": "44 minutes, 12 seconds and 901 milliseconds",
"collection_time_in_millis": 2652901
}
}
},
"mem": {
"heap_committed": "7.9gb",
"heap_committed_in_bytes": 8572502016,
"heap_used": "3.8gb",
"heap_used_in_bytes": 4150505720,
"non_heap_committed": "86.8mb",
"non_heap_committed_in_bytes": 91115520,
"non_heap_used": "57mb",
"non_heap_used_in_bytes": 59847224,
"pools": {
"CMS Old Gen": {
"max": "7.8gb",
"max_in_bytes": 8415477760,
"peak_max": "7.8gb",
"peak_max_in_bytes": 8415477760,
"peak_used": "7.8gb",
"peak_used_in_bytes": 8413722272,
"used": "3.7gb",
"used_in_bytes": 4030374000
},
"CMS Perm Gen": {
"max": "1gb",
"max_in_bytes": 1073741824,
"peak_max": "1gb",
"peak_max_in_bytes": 1073741824,
"peak_used": "44.1mb",
"peak_used_in_bytes": 46268600,
"used": "44.1mb",
"used_in_bytes": 46268600
},
"Code Cache": {
"max": "48mb",
"max_in_bytes": 50331648,
"peak_max": "48mb",
"peak_max_in_bytes": 50331648,
"peak_used": "13mb",
"peak_used_in_bytes": 13705984,
"used": "12.9mb",
"used_in_bytes": 13578624
},
"Par Eden Space": {
"max": "133.1mb",
"max_in_bytes": 139591680,
"peak_max": "133.1mb",
"peak_max_in_bytes": 139591680,
"peak_used": "133.1mb",
"peak_used_in_bytes": 139591680,
"used": "113.6mb",
"used_in_bytes": 119180776
},
"Par Survivor Space": {
"max": "16.6mb",
"max_in_bytes": 17432576,
"peak_max": "16.6mb",
"peak_max_in_bytes": 17432576,
"peak_used": "16.6mb",
"peak_used_in_bytes": 17432576,
"used": "928.6kb",
"used_in_bytes": 950944
}
}
},
"threads": {
"count": 51,
"peak_count": 495
},
"timestamp": 1378496996332,
"uptime": "15 hours, 40 minutes, 8 seconds and 412 milliseconds",
"uptime_in_millis": 56408412
},
"name": "N'Garai",
"network": {
"tcp": {
"active_opens": 35069,
"attempt_fails": 17,
"curr_estab": 83,
"estab_resets": 250,
"in_errs": 0,
"in_segs": 78298021,
"out_rsts": 11407,
"out_segs": 77643508,
"passive_opens": 39077,
"retrans_segs": 73385
}
},
"os": {
"cpu": {
"idle": 98,
"sys": 0,
"user": 0
},
"load_average": [
0.16,
0.059999999999999998,
0.059999999999999998
],
"mem": {
"actual_free": "6.3gb",
"actual_free_in_bytes": 6780661760,
"actual_used": "10.3gb",
"actual_used_in_bytes": 11133403136,
"free": "3.7gb",
"free_in_bytes": 4075761664,
"free_percent": 37,
"used": "12.8gb",
"used_in_bytes": 13838303232,
"used_percent": 62
},
"swap": {
"free": "0b",
"free_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
},
"timestamp": 1378496996329,
"uptime": "15 hours, 43 minutes and 31 seconds",
"uptime_in_millis": 56611000
},
"process": {
"cpu": {
"percent": 0,
"sys": "2 hours, 17 minutes, 48 seconds and 420 milliseconds",
"sys_in_millis": 8268420,
"total": "9 hours, 54 minutes, 58 seconds and 730 milliseconds",
"total_in_millis": 35698730,
"user": "7 hours, 37 minutes, 10 seconds and 310 milliseconds",
"user_in_millis": 27430310
},
"mem": {
"resident": "9.5gb",
"resident_in_bytes": 10238775296,
"share": "114.1mb",
"share_in_bytes": 119738368,
"total_virtual": "10.4gb",
"total_virtual_in_bytes": 11256926208
},
"open_file_descriptors": 880,
"timestamp": 1378496996329
},
"thread_pool": {
"bulk": {
"active": 0,
"completed": 439949,
"largest": 36,
"queue": 0,
"rejected": 0,
"threads": 0
},
"cache": {
"active": 0,
"completed": 535929,
"largest": 4,
"queue": 0,
"threads": 1
},
"flush": {
"active": 0,
"completed": 1140,
"largest": 10,
"queue": 0,
"threads": 4
},
"generic": {
"active": 0,
"completed": 95073,
"largest": 6,
"queue": 0,
"rejected": 0,
"threads": 1
},
"get": {
"active": 0,
"completed": 614491,
"largest": 30,
"queue": 0,
"rejected": 0,
"threads": 0
},
"index": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"management": {
"active": 1,
"completed": 8605,
"largest": 3,
"queue": 0,
"threads": 3
},
"merge": {
"active": 0,
"completed": 237641,
"largest": 20,
"queue": 0,
"threads": 1
},
"percolate": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"refresh": {
"active": 0,
"completed": 269338,
"largest": 10,
"queue": 0,
"threads": 1
},
"search": {
"active": 0,
"completed": 25505973,
"largest": 332,
"queue": 0,
"rejected": 0,
"threads": 0
},
"snapshot": {
"active": 0,
"completed": 82553,
"largest": 5,
"queue": 0,
"threads": 1
}
},
"timestamp": 1378496996328,
"transport": {
"rx_count": 69348105,
"rx_size": "8.9gb",
"rx_size_in_bytes": 9630178189,
"server_open": 45,
"tx_count": 35512709,
"tx_size": "10.7gb",
"tx_size_in_bytes": 11517079589
},
"transport_address": "inet[/xxxxxxxxxxxxx:9300]"
},

ES 0.90.3 :
=========

{
"cluster_name": "xxxxxxxxxxxxxxxxxx",
"nodes": {
"9fO78qRWROK5untwFS_zjg": {
"fs": {
"data": [
{
"available": "408.6gb",
"available_in_bytes": 438829277184,
"dev": "/dev/xvdb",
"disk_read_size": "1.5mb",
"disk_read_size_in_bytes": 1635840,
"disk_reads": 439,
"disk_write_size": "99.2gb",
"disk_write_size_in_bytes": 106535511040,
"disk_writes": 2753515,
"free": "408.6gb",
"free_in_bytes": 438829277184,
"total": "409.7gb",
"total_in_bytes": 439983034368
}
],
"timestamp": 1378496012942
},
"hostname": "xxxxxxxxxxxxxxxxxxxxx",
"http": {
"current_open": 5,
"total_opened": 20503
},
"indices": {
"docs": {
"count": 439882,
"deleted": 24477
},
"fielddata": {
"evictions": 0,
"memory_size": "0b",
"memory_size_in_bytes": 0
},
"filter_cache": {
"evictions": 0,
"memory_size": "0b",
"memory_size_in_bytes": 0
},
"flush": {
"total": 1026,
"total_time": "11.3m",
"total_time_in_millis": 679732
},
"get": {
"current": 0,
"exists_time": "2.3m",
"exists_time_in_millis": 141261,
"exists_total": 395109,
"get_time": "3m",
"missing_time": "43s",
"missing_time_in_millis": 43077,
"missing_total": 316702,
"time_in_millis": 184338,
"total": 711811
},
"id_cache": {
"memory_size": "0b",
"memory_size_in_bytes": 0
},
"indexing": {
"delete_current": 0,
"delete_time": "0s",
"delete_time_in_millis": 0,
"delete_total": 0,
"index_current": 0,
"index_time": "1.3h",
"index_time_in_millis": 5019993,
"index_total": 508581
},
"merges": {
"current": 0,
"current_docs": 0,
"current_size": "0b",
"current_size_in_bytes": 0,
"total": 0,
"total_docs": 0,
"total_size": "0b",
"total_size_in_bytes": 0,
"total_time": "0s",
"total_time_in_millis": 0
},
"refresh": {
"total": 704132,
"total_time": "1.5d",
"total_time_in_millis": 135699014
},
"search": {
"fetch_current": 0,
"fetch_time": "4.9m",
"fetch_time_in_millis": 296173,
"fetch_total": 87277,
"open_contexts": 0,
"query_current": 0,
"query_time": "1.4d",
"query_time_in_millis": 122853699,
"query_total": 23079777
},
"store": {
"size": "1010mb",
"size_in_bytes": 1059109597,
"throttle_time": "1.5d",
"throttle_time_in_millis": 131598086
},
"warmer": {
"current": 0,
"total": 354301,
"total_time": "3.4h",
"total_time_in_millis": 12513103
}
},
"jvm": {
"buffer_pools": {
"direct": {
"count": 626,
"total_capacity": "32mb",
"total_capacity_in_bytes": 33558076,
"used": "32mb",
"used_in_bytes": 33558076
},
"mapped": {
"count": 0,
"total_capacity": "0b",
"total_capacity_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
}
},
"gc": {
"collection_count": 139037,
"collection_time": "2 hours, 26 minutes, 37 seconds and 188 milliseconds",
"collection_time_in_millis": 8797188,
"collectors": {
"ConcurrentMarkSweep": {
"collection_count": 51,
"collection_time": "5 seconds and 755 milliseconds",
"collection_time_in_millis": 5755
},
"ParNew": {
"collection_count": 138986,
"collection_time": "2 hours, 26 minutes, 31 seconds and 433 milliseconds",
"collection_time_in_millis": 8791433
}
}
},
"mem": {
"heap_committed": "7.9gb",
"heap_committed_in_bytes": 8572502016,
"heap_used": "2.9gb",
"heap_used_in_bytes": 3208401136,
"non_heap_committed": "88.1mb",
"non_heap_committed_in_bytes": 92438528,
"non_heap_used": "57.1mb",
"non_heap_used_in_bytes": 59963776,
"pools": {
"CMS Old Gen": {
"max": "7.8gb",
"max_in_bytes": 8415477760,
"peak_max": "7.8gb",
"peak_max_in_bytes": 8415477760,
"peak_used": "6.9gb",
"peak_used_in_bytes": 7462132504,
"used": "2.8gb",
"used_in_bytes": 3106353392
},
"CMS Perm Gen": {
"max": "1gb",
"max_in_bytes": 1073741824,
"peak_max": "1gb",
"peak_max_in_bytes": 1073741824,
"peak_used": "46.1mb",
"peak_used_in_bytes": 48350272,
"used": "46.1mb",
"used_in_bytes": 48350272
},
"Code Cache": {
"max": "48mb",
"max_in_bytes": 50331648,
"peak_max": "48mb",
"peak_max_in_bytes": 50331648,
"peak_used": "11mb",
"peak_used_in_bytes": 11623808,
"used": "11mb",
"used_in_bytes": 11613504
},
"Par Eden Space": {
"max": "133.1mb",
"max_in_bytes": 139591680,
"peak_max": "133.1mb",
"peak_max_in_bytes": 139591680,
"peak_used": "133.1mb",
"peak_used_in_bytes": 139591680,
"used": "96.5mb",
"used_in_bytes": 101288456
},
"Par Survivor Space": {
"max": "16.6mb",
"max_in_bytes": 17432576,
"peak_max": "16.6mb",
"peak_max_in_bytes": 17432576,
"peak_used": "16.6mb",
"peak_used_in_bytes": 17432576,
"used": "741.4kb",
"used_in_bytes": 759288
}
}
},
"threads": {
"count": 348,
"peak_count": 377
},
"timestamp": 1378496012941,
"uptime": "14 hours, 25 minutes, 2 seconds and 241 milliseconds",
"uptime_in_millis": 51902241
},
"name": "Straw Man",
"network": {
"tcp": {
"active_opens": 33696,
"attempt_fails": 166,
"curr_estab": 97,
"estab_resets": 217,
"in_errs": 0,
"in_segs": 68455896,
"out_rsts": 10889,
"out_segs": 69298945,
"passive_opens": 36401,
"retrans_segs": 20613
}
},
"os": {
"cpu": {
"idle": 96,
"stolen": 0,
"sys": 1,
"user": 1
},
"load_average": [
0.0,
0.01,
0.050000000000000003
],
"mem": {
"actual_free": "6gb",
"actual_free_in_bytes": 6469910528,
"actual_used": "10.6gb",
"actual_used_in_bytes": 11444154368,
"free": "4.4gb",
"free_in_bytes": 4800462848,
"free_percent": 36,
"used": "12.2gb",
"used_in_bytes": 13113602048,
"used_percent": 63
},
"swap": {
"free": "0b",
"free_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
},
"timestamp": 1378496012939,
"uptime": "14 hours, 39 minutes and 36 seconds",
"uptime_in_millis": 52776000
},
"process": {
"cpu": {
"percent": 0,
"sys": "1 hour, 29 minutes, 23 seconds and 380 milliseconds",
"sys_in_millis": 5363380,
"total": "12 hours, 6 minutes, 25 seconds and 160 milliseconds",
"total_in_millis": 43585160,
"user": "10 hours, 37 minutes, 1 second and 780 milliseconds",
"user_in_millis": 38221780
},
"mem": {
"resident": "9.5gb",
"resident_in_bytes": 10250309632,
"share": "114mb",
"share_in_bytes": 119640064,
"total_virtual": "10.4gb",
"total_virtual_in_bytes": 11271077888
},
"open_file_descriptors": 500,
"timestamp": 1378496012939
},
"thread_pool": {
"bulk": {
"active": 0,
"completed": 400897,
"largest": 100,
"queue": 0,
"rejected": 0,
"threads": 100
},
"flush": {
"active": 0,
"completed": 1026,
"largest": 1,
"queue": 0,
"threads": 1
},
"generic": {
"active": 0,
"completed": 182321,
"largest": 7,
"queue": 0,
"rejected": 0,
"threads": 2
},
"get": {
"active": 0,
"completed": 563166,
"largest": 100,
"queue": 0,
"rejected": 0,
"threads": 100
},
"index": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"management": {
"active": 1,
"completed": 7816,
"largest": 2,
"queue": 0,
"threads": 2
},
"merge": {
"active": 0,
"completed": 230691,
"largest": 1,
"queue": 0,
"threads": 1
},
"optimize": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"percolate": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"refresh": {
"active": 0,
"completed": 207176,
"largest": 1,
"queue": 0,
"threads": 1
},
"search": {
"active": 0,
"completed": 23174840,
"largest": 100,
"queue": 0,
"rejected": 0,
"threads": 100
},
"snapshot": {
"active": 0,
"completed": 91949,
"largest": 1,
"queue": 0,
"threads": 1
},
"warmer": {
"active": 0,
"completed": 354301,
"largest": 1,
"queue": 0,
"threads": 1
}
},
"timestamp": 1378496012938,
"transport": {
"rx_count": 64202809,
"rx_size": "8.1gb",
"rx_size_in_bytes": 8780422032,
"server_open": 52,
"tx_count": 28166345,
"tx_size": "9.3gb",
"tx_size_in_bytes": 10007230919
},
"transport_address": "inet[/xxxxxxxxxxxxxxxx:9300]"
},

===============================================================================================================================================
Experiment 2: Based on the result of the previous experiment I tuned the JVM parameters in ES 0.90.3 and also used a smaller dataset 100K documents to speed up my benchmarking
================================================================================================================================================

DataSize: 100k documents
Total Size: 122 MB

ES Cluster Size: 3 nodes (AWS EC2 m2.xlarge instance (Memory 17.1 GB, Compute Units: 6))

of Index : 7

of shards for each index: 6

of replicas for each shard: 1

JVM (oracle 1.7.0_13 ) parameter tuning of ES 0.90.3 ( Increased heap size, etc. It reduced GC time but not up to the point I expected):
===========================================================================================

wrapper.java.additional.1=-Delasticsearch-service
wrapper.java.additional.2=-Des.path.home=%ES_HOME%
wrapper.java.additional.3=-Xss256k
wrapper.java.additional.4=-XX:+UseParNewGC
wrapper.java.additional.5=-XX:+UseConcMarkSweepGC
wrapper.java.additional.6=-XX:CMSInitiatingOccupancyFraction=75
wrapper.java.additional.7=-XX:+UseCMSInitiatingOccupancyOnly
wrapper.java.additional.8=-XX:+HeapDumpOnOutOfMemoryError
wrapper.java.additional.9=-XX:+CMSParallelRemarkEnabled
wrapper.java.additional.10=-XX:+UseTLAB
wrapper.java.additional.11=-XX:+CMSClassUnloadingEnabled
wrapper.java.additional.12=-XX:+CMSPermGenSweepingEnabled
wrapper.java.additional.13=-Djava.awt.headless=true
wrapper.java.additional.14=-XX:MaxPermSize=%MAX_PERMGEN_MB%m
wrapper.java.additional.15=-Des.max-open-files=true

Initial Java Heap Size (in MB)

wrapper.java.initmemory=10240

Maximum Java Heap Size (in MB)

wrapper.java.maxmemory=10240

JVM settings of ES 0.20.6 is same as the previous experiment

Indexing time :
============

ES 0.20.6 : 47 minutes (approx)
ES 0.90.3 : 1 hr 15 minutes (approx)

Index Stat (providing info of just one node from the clusters of each version)
============================================================

ES 0.20.6:
========

{
"cluster_name": "xxxxxxxxxxxxxxxxxxxxxxxxx",
"nodes": {
"_TgElhK5SG6ig70QgtUuWA": {
"fs": {
"data": [
{
"available": "409.3gb",
"available_in_bytes": 439545597952,
"dev": "/dev/xvdb",
"disk_read_size": "1.5mb",
"disk_read_size_in_bytes": 1627648,
"disk_reads": 437,
"disk_write_size": "8.1gb",
"disk_write_size_in_bytes": 8788468224,
"disk_writes": 230370,
"free": "409.3gb",
"free_in_bytes": 439545597952,
"total": "409.7gb",
"total_in_bytes": 439983034368
}
],
"timestamp": 1378839509732
},
"hostname": "xxxxxxxxx",
"http": {
"current_open": 3,
"total_opened": 2744
},
"indices": {
"cache": {
"bloom_size": "2.5kb",
"bloom_size_in_bytes": 2624,
"field_evictions": 0,
"field_size": "0b",
"field_size_in_bytes": 0,
"filter_count": 0,
"filter_evictions": 0,
"filter_size": "0b",
"filter_size_in_bytes": 0,
"id_cache_size": "0b",
"id_cache_size_in_bytes": 0
},
"docs": {
"count": 80170,
"deleted": 1988
},
"flush": {
"total": 114,
"total_time": "21.6s",
"total_time_in_millis": 21674
},
"get": {
"current": 0,
"exists_time": "37.5s",
"exists_time_in_millis": 37551,
"exists_total": 79338,
"missing_time": "29s",
"missing_time_in_millis": 29035,
"missing_total": 58383,
"time": "1.1m",
"time_in_millis": 66586,
"total": 137721
},
"indexing": {
"delete_current": 0,
"delete_time": "0s",
"delete_time_in_millis": 0,
"delete_total": 0,
"index_current": 0,
"index_time": "15.9m",
"index_time_in_millis": 954405,
"index_total": 99349
},
"merges": {
"current": 0,
"current_docs": 0,
"current_size": "0b",
"current_size_in_bytes": 0,
"total": 124,
"total_docs": 35300,
"total_size": "24.4mb",
"total_size_in_bytes": 25684710,
"total_time": "43.8s",
"total_time_in_millis": 43816
},
"refresh": {
"total": 143920,
"total_time": "2.2h",
"total_time_in_millis": 8158194
},
"search": {
"fetch_current": 0,
"fetch_time": "30s",
"fetch_time_in_millis": 30052,
"fetch_total": 19914,
"query_current": 0,
"query_time": "2.8h",
"query_time_in_millis": 10325711,
"query_total": 4699230
},
"store": {
"size": "331.4mb",
"size_in_bytes": 347597175,
"throttle_time": "0s",
"throttle_time_in_millis": 0
}
},
"jvm": {
"buffer_pools": {
"direct": {
"count": 569,
"total_capacity": "15.4mb",
"total_capacity_in_bytes": 16170093,
"used": "15.4mb",
"used_in_bytes": 16170093
},
"mapped": {
"count": 0,
"total_capacity": "0b",
"total_capacity_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
}
},
"gc": {
"collection_count": 2987,
"collection_time": "6 minutes, 19 seconds and 977 milliseconds",
"collection_time_in_millis": 379977,
"collectors": {
"ConcurrentMarkSweep": {
"collection_count": 6,
"collection_time": "9 seconds and 261 milliseconds",
"collection_time_in_millis": 9261
},
"ParNew": {
"collection_count": 2981,
"collection_time": "6 minutes, 10 seconds and 716 milliseconds",
"collection_time_in_millis": 370716
}
}
},
"mem": {
"heap_committed": "7.9gb",
"heap_committed_in_bytes": 8572502016,
"heap_used": "1.9gb",
"heap_used_in_bytes": 2071669064,
"non_heap_committed": "86.8mb",
"non_heap_committed_in_bytes": 91103232,
"non_heap_used": "57.1mb",
"non_heap_used_in_bytes": 59934008,
"pools": {
"CMS Old Gen": {
"max": "7.8gb",
"max_in_bytes": 8415477760,
"peak_max": "7.8gb",
"peak_max_in_bytes": 8415477760,
"peak_used": "7.8gb",
"peak_used_in_bytes": 8401194792,
"used": "1.8gb",
"used_in_bytes": 1993829920
},
"CMS Perm Gen": {
"max": "1gb",
"max_in_bytes": 1073741824,
"peak_max": "1gb",
"peak_max_in_bytes": 1073741824,
"peak_used": "44.1mb",
"peak_used_in_bytes": 46285624,
"used": "44.1mb",
"used_in_bytes": 46285624
},
"Code Cache": {
"max": "48mb",
"max_in_bytes": 50331648,
"peak_max": "48mb",
"peak_max_in_bytes": 50331648,
"peak_used": "13mb",
"peak_used_in_bytes": 13657792,
"used": "13mb",
"used_in_bytes": 13648384
},
"Par Eden Space": {
"max": "133.1mb",
"max_in_bytes": 139591680,
"peak_max": "133.1mb",
"peak_max_in_bytes": 139591680,
"peak_used": "133.1mb",
"peak_used_in_bytes": 139591680,
"used": "62.9mb",
"used_in_bytes": 66003288
},
"Par Survivor Space": {
"max": "16.6mb",
"max_in_bytes": 17432576,
"peak_max": "16.6mb",
"peak_max_in_bytes": 17432576,
"peak_used": "16.6mb",
"peak_used_in_bytes": 17432576,
"used": "11.2mb",
"used_in_bytes": 11835856
}
}
},
"threads": {
"count": 53,
"peak_count": 413
},
"timestamp": 1378839509732,
"uptime": "2 hours, 1 minute, 52 seconds and 822 milliseconds",
"uptime_in_millis": 7312822
},
"name": "Caiman",
"network": {
"tcp": {
"active_opens": 4889,
"attempt_fails": 18,
"curr_estab": 82,
"estab_resets": 39,
"in_errs": 0,
"in_segs": 14502072,
"out_rsts": 1504,
"out_segs": 14696445,
"passive_opens": 4893,
"retrans_segs": 7653
}
},
"os": {
"cpu": {
"idle": 98,
"sys": 1,
"user": 0
},
"load_average": [
0.040000000000000001,
0.029999999999999999,
1.76
],
"mem": {
"actual_free": "6.8gb",
"actual_free_in_bytes": 7397154816,
"actual_used": "9.7gb",
"actual_used_in_bytes": 10516910080,
"free": "6gb",
"free_in_bytes": 6489812992,
"free_percent": 41,
"used": "10.6gb",
"used_in_bytes": 11424251904,
"used_percent": 58
},
"swap": {
"free": "0b",
"free_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
},
"timestamp": 1378839509729,
"uptime": "2 hours, 4 minutes and 32 seconds",
"uptime_in_millis": 7472000
},
"process": {
"cpu": {
"percent": 0,
"sys": "23 minutes, 27 seconds and 670 milliseconds",
"sys_in_millis": 1407670,
"total": "1 hour, 34 minutes, 1 second and 500 milliseconds",
"total_in_millis": 5641500,
"user": "1 hour, 10 minutes, 33 seconds and 830 milliseconds",
"user_in_millis": 4233830
},
"mem": {
"resident": "9.5gb",
"resident_in_bytes": 10254131200,
"share": "114.1mb",
"share_in_bytes": 119738368,
"total_virtual": "10.4gb",
"total_virtual_in_bytes": 11231289344
},
"open_file_descriptors": 641,
"timestamp": 1378839509730
},
"thread_pool": {
"bulk": {
"active": 0,
"completed": 78193,
"largest": 30,
"queue": 0,
"rejected": 0,
"threads": 0
},
"cache": {
"active": 0,
"completed": 91637,
"largest": 4,
"queue": 0,
"threads": 1
},
"flush": {
"active": 0,
"completed": 114,
"largest": 10,
"queue": 0,
"threads": 4
},
"generic": {
"active": 0,
"completed": 14037,
"largest": 6,
"queue": 0,
"rejected": 0,
"threads": 2
},
"get": {
"active": 0,
"completed": 110380,
"largest": 20,
"queue": 0,
"rejected": 0,
"threads": 0
},
"index": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"management": {
"active": 1,
"completed": 1034,
"largest": 3,
"queue": 0,
"threads": 3
},
"merge": {
"active": 0,
"completed": 39318,
"largest": 14,
"queue": 0,
"threads": 1
},
"percolate": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"refresh": {
"active": 0,
"completed": 45668,
"largest": 10,
"queue": 0,
"threads": 1
},
"search": {
"active": 0,
"completed": 4797430,
"largest": 284,
"queue": 0,
"rejected": 0,
"threads": 1
},
"snapshot": {
"active": 0,
"completed": 13110,
"largest": 5,
"queue": 0,
"threads": 1
}
},
"timestamp": 1378839509729,
"transport": {
"rx_count": 13048268,
"rx_size": "1.7gb",
"rx_size_in_bytes": 1826332161,
"server_open": 47,
"tx_count": 6940502,
"tx_size": "1.9gb",
"tx_size_in_bytes": 2097714927
},
"transport_address": "inet[/xxxxxxxxx:9300]"
}

ES 0.90.3 :
=========

{
"cluster_name": "xxxxxxxxxx",
"nodes": {
"5bEIQiM7QNqcwlUHP7nCJA": {
"fs": {
"data": [
{
"available": "409.4gb",
"available_in_bytes": 439677587456,
"dev": "/dev/xvdb",
"disk_read_size": "1.5mb",
"disk_read_size_in_bytes": 1639936,
"disk_reads": 440,
"disk_write_size": "16.1gb",
"disk_write_size_in_bytes": 17383471104,
"disk_writes": 498923,
"free": "409.4gb",
"free_in_bytes": 439677587456,
"total": "409.7gb",
"total_in_bytes": 439983034368
}
],
"timestamp": 1378839121916
},
"hostname": "xxxxxxx",
"http": {
"current_open": 5,
"total_opened": 3418
},
"indices": {
"docs": {
"count": 84675,
"deleted": 3008
},
"fielddata": {
"evictions": 0,
"memory_size": "2.6mb",
"memory_size_in_bytes": 2729964
},
"filter_cache": {
"evictions": 0,
"memory_size": "8.6kb",
"memory_size_in_bytes": 8896
},
"flush": {
"total": 152,
"total_time": "1.8m",
"total_time_in_millis": 110817
},
"get": {
"current": 0,
"exists_time": "1.4m",
"exists_time_in_millis": 87195,
"exists_total": 75342,
"get_time": "1.7m",
"missing_time": "19.1s",
"missing_time_in_millis": 19156,
"missing_total": 61402,
"time_in_millis": 106351,
"total": 136744
},
"id_cache": {
"memory_size": "0b",
"memory_size_in_bytes": 0
},
"indexing": {
"delete_current": 0,
"delete_time": "0s",
"delete_time_in_millis": 0,
"delete_total": 0,
"index_current": 0,
"index_time": "36.8m",
"index_time_in_millis": 2208906,
"index_total": 97192
},
"merges": {
"current": 0,
"current_docs": 0,
"current_size": "0b",
"current_size_in_bytes": 0,
"total": 7935,
"total_docs": 8925968,
"total_size": "17.4gb",
"total_size_in_bytes": 18726317481,
"total_time": "23.5h",
"total_time_in_millis": 84907064
},
"refresh": {
"total": 146975,
"total_time": "8.5h",
"total_time_in_millis": 30620105
},
"search": {
"fetch_current": 0,
"fetch_time": "45.4s",
"fetch_time_in_millis": 45409,
"fetch_total": 17271,
"open_contexts": 0,
"query_current": 0,
"query_time": "2.7h",
"query_time_in_millis": 9818367,
"query_total": 4486692
},
"store": {
"size": "201mb",
"size_in_bytes": 210776029,
"throttle_time": "5.3h",
"throttle_time_in_millis": 19215583
},
"warmer": {
"current": 0,
"total": 71727,
"total_time": "34.6m",
"total_time_in_millis": 2077566
}
},
"jvm": {
"buffer_pools": {
"direct": {
"count": 939,
"total_capacity": "19.7mb",
"total_capacity_in_bytes": 20747716,
"used": "19.7mb",
"used_in_bytes": 20747716
},
"mapped": {
"count": 0,
"total_capacity": "0b",
"total_capacity_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
}
},
"gc": {
"collection_count": 61441,
"collection_time": "1 hour, 7 minutes, 53 seconds and 232 milliseconds",
"collection_time_in_millis": 4073232,
"collectors": {
"ConcurrentMarkSweep": {
"collection_count": 86,
"collection_time": "7 seconds and 277 milliseconds",
"collection_time_in_millis": 7277
},
"ParNew": {
"collection_count": 61355,
"collection_time": "1 hour, 7 minutes, 45 seconds and 955 milliseconds",
"collection_time_in_millis": 4065955
}
}
},
"mem": {
"heap_committed": "7.9gb",
"heap_committed_in_bytes": 8583249920,
"heap_used": "413.4mb",
"heap_used_in_bytes": 433566672,
"non_heap_committed": "88.8mb",
"non_heap_committed_in_bytes": 93192192,
"non_heap_used": "57.9mb",
"non_heap_used_in_bytes": 60738288,
"pools": {
"CMS Old Gen": {
"max": "7.9gb",
"max_in_bytes": 8522825728,
"peak_max": "7.9gb",
"peak_max_in_bytes": 8522825728,
"peak_used": "7.9gb",
"peak_used_in_bytes": 8515980304,
"used": "371mb",
"used_in_bytes": 389070136
},
"CMS Perm Gen": {
"max": "1gb",
"max_in_bytes": 1073741824,
"peak_max": "1gb",
"peak_max_in_bytes": 1073741824,
"peak_used": "45.9mb",
"peak_used_in_bytes": 48160240,
"used": "45.9mb",
"used_in_bytes": 48160240
},
"Code Cache": {
"max": "48mb",
"max_in_bytes": 50331648,
"peak_max": "48mb",
"peak_max_in_bytes": 50331648,
"peak_used": "12mb",
"peak_used_in_bytes": 12605120,
"used": "11.9mb",
"used_in_bytes": 12578048
},
"Par Eden Space": {
"max": "51.2mb",
"max_in_bytes": 53739520,
"peak_max": "51.2mb",
"peak_max_in_bytes": 53739520,
"peak_used": "51.2mb",
"peak_used_in_bytes": 53739520,
"used": "36mb",
"used_in_bytes": 37811864
},
"Par Survivor Space": {
"max": "6.3mb",
"max_in_bytes": 6684672,
"peak_max": "6.3mb",
"peak_max_in_bytes": 6684672,
"peak_used": "6.3mb",
"peak_used_in_bytes": 6684672,
"used": "6.3mb",
"used_in_bytes": 6684672
}
}
},
"threads": {
"count": 948,
"peak_count": 973
},
"timestamp": 1378839121915,
"uptime": "2 hours, 34 minutes, 28 seconds and 787 milliseconds",
"uptime_in_millis": 9268787
},
"name": "Anti-Cap",
"network": {
"tcp": {
"active_opens": 7297,
"attempt_fails": 47,
"curr_estab": 94,
"estab_resets": 55,
"in_errs": 0,
"in_segs": 14752680,
"out_rsts": 2459,
"out_segs": 14638367,
"passive_opens": 7308,
"retrans_segs": 660
}
},
"os": {
"cpu": {
"idle": 99,
"stolen": 0,
"sys": 0,
"user": 0
},
"load_average": [
0.01,
1.4099999999999999,
5.2000000000000002
],
"mem": {
"actual_free": "6.7gb",
"actual_free_in_bytes": 7250518016,
"actual_used": "9.9gb",
"actual_used_in_bytes": 10663546880,
"free": "6gb",
"free_in_bytes": 6470684672,
"free_percent": 40,
"used": "10.6gb",
"used_in_bytes": 11443380224,
"used_percent": 59
},
"swap": {
"free": "0b",
"free_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
},
"timestamp": 1378839121912,
"uptime": "3 hours, 8 minutes and 35 seconds",
"uptime_in_millis": 11315000
},
"process": {
"cpu": {
"percent": 0,
"sys": "18 minutes, 43 seconds and 40 milliseconds",
"sys_in_millis": 1123040,
"total": "3 hours, 44 minutes, 47 seconds and 790 milliseconds",
"total_in_millis": 13487790,
"user": "3 hours, 26 minutes, 4 seconds and 750 milliseconds",
"user_in_millis": 12364750
},
"mem": {
"resident": "9.5gb",
"resident_in_bytes": 10241036288,
"share": "114mb",
"share_in_bytes": 119640064,
"total_virtual": "10.6gb",
"total_virtual_in_bytes": 11434696704
},
"open_file_descriptors": 491,
"timestamp": 1378839121912
},
"thread_pool": {
"bulk": {
"active": 0,
"completed": 76697,
"largest": 300,
"queue": 0,
"rejected": 0,
"threads": 300
},
"flush": {
"active": 0,
"completed": 152,
"largest": 1,
"queue": 0,
"threads": 1
},
"generic": {
"active": 0,
"completed": 41242,
"largest": 6,
"queue": 0,
"rejected": 0,
"threads": 2
},
"get": {
"active": 0,
"completed": 107900,
"largest": 300,
"queue": 0,
"rejected": 0,
"threads": 300
},
"index": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"management": {
"active": 1,
"completed": 1252,
"largest": 2,
"queue": 0,
"threads": 2
},
"merge": {
"active": 0,
"completed": 53635,
"largest": 1,
"queue": 0,
"threads": 1
},
"optimize": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"percolate": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"refresh": {
"active": 0,
"completed": 48912,
"largest": 1,
"queue": 0,
"threads": 1
},
"search": {
"active": 0,
"completed": 4511389,
"largest": 300,
"queue": 0,
"rejected": 0,
"threads": 300
},
"snapshot": {
"active": 0,
"completed": 26419,
"largest": 1,
"queue": 0,
"threads": 1
},
"warmer": {
"active": 0,
"completed": 71727,
"largest": 1,
"queue": 0,
"threads": 1
}
},
"timestamp": 1378839122688,
"transport": {
"rx_count": 12516797,
"rx_size": "1.5gb",
"rx_size_in_bytes": 1691542955,
"server_open": 52,
"tx_count": 5417689,
"tx_size": "1.8gb",
"tx_size_in_bytes": 1959543432
},
"transport_address": "inet[/xxxxxxxxx:9300]"
},


(Jörg Prante) #2

Can you post your index settings and mapping, and an example of one doc (or
instructions how to fill fields of the doc)? And, what is the Java JVM
version you used? Otherwise your observations can't get reproduced (I do
not trust anything measured in cloud envs)

Judging from the disk space consumed, the 0.90 test generates a lot more
data on disk. Not surprisingly this must take longer. Also note, beside
Lucene 3 and 4 difference, that ES default compression is different between
0.20 and 0.90, which makes fair comparisons hard.

Jörg

--
You received this message because you are subscribed to the Google Groups "elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an email to elasticsearch+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.


(aaron) #3

So are you saying that 0.90/Lucene4 use larger data structures on disk? If
that's the case, that would explain why 0.90 is less performant than 0.20.
If so, why the larger data structures? I was hoping for better performance
when upgrading 0.90 from 0.20.

On Wednesday, September 18, 2013 3:15:02 PM UTC-5, Jörg Prante wrote:

Can you post your index settings and mapping, and an example of one doc
(or instructions how to fill fields of the doc)? And, what is the Java JVM
version you used? Otherwise your observations can't get reproduced (I do
not trust anything measured in cloud envs)

Judging from the disk space consumed, the 0.90 test generates a lot more
data on disk. Not surprisingly this must take longer. Also note, beside
Lucene 3 and 4 difference, that ES default compression is different between
0.20 and 0.90, which makes fair comparisons hard.

Jörg

--
You received this message because you are subscribed to the Google Groups "elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an email to elasticsearch+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.


(David Pilato) #4

I did the same experience as you.
The conclusion was somehow that when you compare, you have to compare everything.

For example:
What was your query time in 0.20 and what is it now in 0.90.

In 0.90, indexing comes with a cost but you get much more gain on query time. This is the trade here.
Let's say that the purpose of elasticsearch is more about querying than about storing, right? :smiley:

My 2 cents

--
David Pilato | Technical Advocate | Elasticsearch.com
@dadoonet | @elasticsearchfr | @scrutmydocs

Le 18 sept. 2013 à 21:33, Ahaduzzaman Munna ahaduzzaman.munna@gmail.com a écrit :

Summary:

Apologize at the beginning for this long post but thought it's worth sharing the result. I did a benchmarking for the indexing time using Elasticsearch 0.90.3 version and compared that to 0.20.6 version. Surprisingly ES 0.90.3 performed worse than ES 0.20.6 version. Elasticsearch has a nice API to look into index operation stats (curl "localhost:9200/_nodes/stats?all=true") which I used to find out the reason and found that Garbage Collection ran much much longer in ES 0.90.3 than ES 0.20.6 ( hours vs minutes). I am not sure whether this is the only reason for ES 0.90.3 to perform worse than the previous version. So, I am seeking experts help here providing the experiment detail for the two experiments I carried out. If required I am willing to share the bulk operations we do against Elasticsearch. Thank you in advance for your thoughts/suggestions/questions.

My Questions to this forum are:

(1) Why does GC in ES 0.90.3 take longer than ES 0.20.6 version having the same JVM setting?
(2) What can we do to improve GC time in ES 0.90.3
(3) Are there any other configurations required to improve indexing time in ES 0.90.3 ( I know this is not a specific question but interested to know the suggestions)

==================================================================================================================
Experiment 1: All settings are absolutely same for both ES version clusters except increased threadpool size and queue_size in ES 0.90.3 version

DataSize: 500K documents
Total Size: 658 MB (approx)
ES Cluster Size: 3 nodes (AWS EC2 m2.xlarge instance (Memory 17.1 GB, Compute Units: 6))

of Index : 7

of shards for each index: 6

of replicas for each shard: 1

JVM settings:

wrapper.java.additional.1=-Delasticsearch-service
wrapper.java.additional.2=-Des.path.home=%ES_HOME%
wrapper.java.additional.3=-Xss256k
wrapper.java.additional.4=-XX:+UseParNewGC
wrapper.java.additional.5=-XX:+UseConcMarkSweepGC
wrapper.java.additional.6=-XX:CMSInitiatingOccupancyFraction=75
wrapper.java.additional.7=-XX:+UseCMSInitiatingOccupancyOnly
wrapper.java.additional.8=-XX:+HeapDumpOnOutOfMemoryError
wrapper.java.additional.9=-Djava.awt.headless=true
wrapper.java.additional.10=-XX:MaxPermSize=1024m
wrapper.java.additional.11=-Des.max-open-files=true

Initial Java Heap Size (in MB)

wrapper.java.initmemory=8192

Maximum Java Heap Size (in MB)

wrapper.java.maxmemory=8192

Indexing time:

ES 0.20.6 : 4 hrs 57 minutes (approx)
ES 0.90.3 : 6 hrs 12 minutes (approx)

Index Stat (providing info of just one node from the clusters of each version)

ES 0.20.6:

{
"cluster_name": "xxxxxxxxx",
"nodes": {
"-j6dAUBySuuDU-nKt7Fyrw": {
"fs": {
"data": [
{
"available": "407.7gb",
"available_in_bytes": 437794705408,
"dev": "/dev/xvdb",
"disk_read_size": "1.5mb",
"disk_read_size_in_bytes": 1627648,
"disk_reads": 437,
"disk_write_size": "68.1gb",
"disk_write_size_in_bytes": 73151741440,
"disk_writes": 1832827,
"free": "407.7gb",
"total": "409.7gb",
"total_in_bytes": 439983034368
}
],
"timestamp": 1378496996333
},
"hostname": "xxxxxxxxxxx",
"http": {
"current_open": 4,
"total_opened": 22243
},
"indices": {
"cache": {
"bloom_size": "0b",
"bloom_size_in_bytes": 0,
"field_evictions": 0,
"field_size": "0b",
"field_size_in_bytes": 0,
"filter_count": 0,
"filter_evictions": 0,
"filter_size": "0b",
"filter_size_in_bytes": 0,
"id_cache_size": "0b",
"id_cache_size_in_bytes": 0
},
"docs": {
"count": 430122,
"deleted": 43501
},
"flush": {
"total": 1140,
"total_time": "3.6m",
"total_time_in_millis": 219575
},
"get": {
"current": 0,
"exists_time": "6.8m",
"exists_time_in_millis": 411873,
"exists_total": 449999,
"missing_time": "3.6m",
"missing_time_in_millis": 218845,
"missing_total": 311984,
"time": "10.5m",
"time_in_millis": 630718,
"total": 761983
},
"indexing": {
"delete_current": 0,
"delete_time": "0s",
"delete_time_in_millis": 0,
"delete_total": 0,
"index_current": 0,
"index_time": "2.3h",
"index_time_in_millis": 8457005,
"index_total": 557055
},
"merges": {
"current": 0,
"current_docs": 0,
"current_size": "0b",
"current_size_in_bytes": 0,
"total": 0,
"total_docs": 0,
"total_size": "0b",
"total_size_in_bytes": 0,
"total_time": "0s",
"total_time_in_millis": 0
},
"refresh": {
"total": 828303,
"total_time": "1d",
"total_time_in_millis": 94763236
},
"search": {
"fetch_current": 0,
"fetch_time": "7m",
"fetch_time_in_millis": 425956,
"fetch_total": 142283,
"query_current": 0,
"query_time": "1d",
"query_time_in_millis": 91201118,
"query_total": 24950295
},
"store": {
"size": "1.9gb",
"size_in_bytes": 2097636533,
"throttle_time": "0s",
"throttle_time_in_millis": 0
}
},
"jvm": {
"buffer_pools": {
"direct": {
"count": 722,
"total_capacity": "24.1mb",
"total_capacity_in_bytes": 25301460,
"used": "24.1mb",
"used_in_bytes": 25301460
},
"mapped": {
"count": 0,
"total_capacity": "0b",
"total_capacity_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
}
},
"gc": {
"collection_count": 20556,
"collection_time": "47 minutes, 30 seconds and 759 milliseconds",
"collection_time_in_millis": 2850759,
"collectors": {
"ConcurrentMarkSweep": {
"collection_count": 37,
"collection_time": "3 minutes, 17 seconds and 858 milliseconds",
"collection_time_in_millis": 197858
},
"ParNew": {
"collection_count": 20519,
"collection_time": "44 minutes, 12 seconds and 901 milliseconds",
"collection_time_in_millis": 2652901
}
}
},
"mem": {
"heap_committed": "7.9gb",
"heap_committed_in_bytes": 8572502016,
"heap_used": "3.8gb",
"heap_used_in_bytes": 4150505720,
"non_heap_committed": "86.8mb",
"non_heap_committed_in_bytes": 91115520,
"non_heap_used": "57mb",
"non_heap_used_in_bytes": 59847224,
"pools": {
"CMS Old Gen": {
"max": "7.8gb",
"max_in_bytes": 8415477760,
"peak_max": "7.8gb",
"peak_max_in_bytes": 8415477760,
"peak_used": "7.8gb",
"peak_used_in_bytes": 8413722272,
"used": "3.7gb",
"used_in_bytes": 4030374000
},
"CMS Perm Gen": {
"max": "1gb",
"max_in_bytes": 1073741824,
"peak_max": "1gb",
"peak_max_in_bytes": 1073741824,
"peak_used": "44.1mb",
"peak_used_in_bytes": 46268600,
"used": "44.1mb",
"used_in_bytes": 46268600
},
"Code Cache": {
"max": "48mb",
"max_in_bytes": 50331648,
"peak_max": "48mb",
"peak_max_in_bytes": 50331648,
"peak_used": "13mb",
"peak_used_in_bytes": 13705984,
"used": "12.9mb",
"used_in_bytes": 13578624
},
"Par Eden Space": {
"max": "133.1mb",
"max_in_bytes": 139591680,
"peak_max": "133.1mb",
"peak_max_in_bytes": 139591680,
"peak_used": "133.1mb",
"peak_used_in_bytes": 139591680,
"used": "113.6mb",
"used_in_bytes": 119180776
},
"Par Survivor Space": {
"max": "16.6mb",
"max_in_bytes": 17432576,
"peak_max": "16.6mb",
"peak_max_in_bytes": 17432576,
"peak_used": "16.6mb",
"peak_used_in_bytes": 17432576,
"used": "928.6kb",
"used_in_bytes": 950944
}
}
},
"threads": {
"count": 51,
"peak_count": 495
},
"timestamp": 1378496996332,
"uptime": "15 hours, 40 minutes, 8 seconds and 412 milliseconds",
"uptime_in_millis": 56408412
},
"name": "N'Garai",
"network": {
"tcp": {
"active_opens": 35069,
"attempt_fails": 17,
"curr_estab": 83,
"estab_resets": 250,
"in_errs": 0,
"in_segs": 78298021,
"out_rsts": 11407,
"out_segs": 77643508,
"passive_opens": 39077,
"retrans_segs": 73385
}
},
"os": {
"cpu": {
"idle": 98,
"sys": 0,
"user": 0
},
"load_average": [
0.16,
0.059999999999999998,
0.059999999999999998
],
"mem": {
"actual_free": "6.3gb",
"actual_free_in_bytes": 6780661760,
"actual_used": "10.3gb",
"actual_used_in_bytes": 11133403136,
"free": "3.7gb",
"free_in_bytes": 4075761664,
"free_percent": 37,
"used": "12.8gb",
"used_in_bytes": 13838303232,
"used_percent": 62
},
"swap": {
"free": "0b",
"free_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
},
"timestamp": 1378496996329,
"uptime": "15 hours, 43 minutes and 31 seconds",
"uptime_in_millis": 56611000
},
"process": {
"cpu": {
"percent": 0,
"sys": "2 hours, 17 minutes, 48 seconds and 420 milliseconds",
"sys_in_millis": 8268420,
"total": "9 hours, 54 minutes, 58 seconds and 730 milliseconds",
"total_in_millis": 35698730,
"user": "7 hours, 37 minutes, 10 seconds and 310 milliseconds",
"user_in_millis": 27430310
},
"mem": {
"resident": "9.5gb",
"resident_in_bytes": 10238775296,
"share": "114.1mb",
"share_in_bytes": 119738368,
"total_virtual": "10.4gb",
"total_virtual_in_bytes": 11256926208
},
"open_file_descriptors": 880,
"timestamp": 1378496996329
},
"thread_pool": {
"bulk": {
"active": 0,
"completed": 439949,
"largest": 36,
"queue": 0,
"rejected": 0,
"threads": 0
},
"cache": {
"active": 0,
"completed": 535929,
"largest": 4,
"queue": 0,
"threads": 1
},
"flush": {
"active": 0,
"completed": 1140,
"largest": 10,
"queue": 0,
"threads": 4
},
"generic": {
"active": 0,
"completed": 95073,
"largest": 6,
"queue": 0,
"rejected": 0,
"threads": 1
},
"get": {
"active": 0,
"completed": 614491,
"largest": 30,
"queue": 0,
"rejected": 0,
"threads": 0
},
"index": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"management": {
"active": 1,
"completed": 8605,
"largest": 3,
"queue": 0,
"threads": 3
},
"merge": {
"active": 0,
"completed": 237641,
"largest": 20,
"queue": 0,
"threads": 1
},
"percolate": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"refresh": {
"active": 0,
"completed": 269338,
"largest": 10,
"queue": 0,
"threads": 1
},
"search": {
"active": 0,
"completed": 25505973,
"largest": 332,
"queue": 0,
"rejected": 0,
"threads": 0
},
"snapshot": {
"active": 0,
"completed": 82553,
"largest": 5,
"queue": 0,
"threads": 1
}
},
"timestamp": 1378496996328,
"transport": {
"rx_count": 69348105,
"rx_size": "8.9gb",
"rx_size_in_bytes": 9630178189,
"server_open": 45,
"tx_count": 35512709,
"tx_size": "10.7gb",
"tx_size_in_bytes": 11517079589
},
"transport_address": "inet[/xxxxxxxxxxxxx:9300]"
},

ES 0.90.3 :

{
"cluster_name": "xxxxxxxxxxxxxxxxxx",
"nodes": {
"9fO78qRWROK5untwFS_zjg": {
"fs": {
"data": [
{
"available": "408.6gb",
"available_in_bytes": 438829277184,
"dev": "/dev/xvdb",
"disk_read_size": "1.5mb",
"disk_read_size_in_bytes": 1635840,
"disk_reads": 439,
"disk_write_size": "99.2gb",
"disk_write_size_in_bytes": 106535511040,
"disk_writes": 2753515,
"free": "408.6gb",
"free_in_bytes": 438829277184,
"total": "409.7gb",
"total_in_bytes": 439983034368
}
],
"timestamp": 1378496012942
},
"hostname": "xxxxxxxxxxxxxxxxxxxxx",
"http": {
"current_open": 5,
"total_opened": 20503
},
"indices": {
"docs": {
"count": 439882,
"deleted": 24477
},
"fielddata": {
"evictions": 0,
"memory_size": "0b",
"memory_size_in_bytes": 0
},
"filter_cache": {
"evictions": 0,
"memory_size": "0b",
"memory_size_in_bytes": 0
},
"flush": {
"total": 1026,
"total_time": "11.3m",
"total_time_in_millis": 679732
},
"get": {
"current": 0,
"exists_time": "2.3m",
"exists_time_in_millis": 141261,
"exists_total": 395109,
"get_time": "3m",
"missing_time": "43s",
"missing_time_in_millis": 43077,
"missing_total": 316702,
"time_in_millis": 184338,
"total": 711811
},
"id_cache": {
"memory_size": "0b",
"memory_size_in_bytes": 0
},
"indexing": {
"delete_current": 0,
"delete_time": "0s",
"delete_time_in_millis": 0,
"delete_total": 0,
"index_current": 0,
"index_time": "1.3h",
"index_time_in_millis": 5019993,
"index_total": 508581
},
"merges": {
"current": 0,
"current_docs": 0,
"current_size": "0b",
"current_size_in_bytes": 0,
"total": 0,
"total_docs": 0,
"total_size": "0b",
"total_size_in_bytes": 0,
"total_time": "0s",
"total_time_in_millis": 0
},
"refresh": {
"total": 704132,
"total_time": "1.5d",
"total_time_in_millis": 135699014
},
"search": {
"fetch_current": 0,
"fetch_time": "4.9m",
"fetch_time_in_millis": 296173,
"fetch_total": 87277,
"open_contexts": 0,
"query_current": 0,
"query_time": "1.4d",
"query_time_in_millis": 122853699,
"query_total": 23079777
},
"store": {
"size": "1010mb",
"size_in_bytes": 1059109597,
"throttle_time": "1.5d",
"throttle_time_in_millis": 131598086
},
"warmer": {
"current": 0,
"total": 354301,
"total_time": "3.4h",
"total_time_in_millis": 12513103
}
},
"jvm": {
"buffer_pools": {
"direct": {
"count": 626,
"total_capacity": "32mb",
"total_capacity_in_bytes": 33558076,
"used": "32mb",
"used_in_bytes": 33558076
},
"mapped": {
"count": 0,
"total_capacity": "0b",
"total_capacity_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
}
},
"gc": {
"collection_count": 139037,
"collection_time": "2 hours, 26 minutes, 37 seconds and 188 milliseconds",
"collection_time_in_millis": 8797188,
"collectors": {
"ConcurrentMarkSweep": {
"collection_count": 51,
"collection_time": "5 seconds and 755 milliseconds",
"collection_time_in_millis": 5755
},
"ParNew": {
"collection_count": 138986,
"collection_time": "2 hours, 26 minutes, 31 seconds and 433 milliseconds",
"collection_time_in_millis": 8791433
}
}
},
"mem": {
"heap_committed": "7.9gb",
"heap_committed_in_bytes": 8572502016,
"heap_used": "2.9gb",
"heap_used_in_bytes": 3208401136,
"non_heap_committed": "88.1mb",
"non_heap_committed_in_bytes": 92438528,
"non_heap_used": "57.1mb",
"non_heap_used_in_bytes": 59963776,
"pools": {
"CMS Old Gen": {
"max": "7.8gb",
"max_in_bytes": 8415477760,
"peak_max": "7.8gb",
"peak_max_in_bytes": 8415477760,
"peak_used": "6.9gb",
"peak_used_in_bytes": 7462132504,
"used": "2.8gb",
"used_in_bytes": 3106353392
},
"CMS Perm Gen": {
"max": "1gb",
"max_in_bytes": 1073741824,
"peak_max": "1gb",
"peak_max_in_bytes": 1073741824,
"peak_used": "46.1mb",
"peak_used_in_bytes": 48350272,
"used": "46.1mb",
"used_in_bytes": 48350272
},
"Code Cache": {
"max": "48mb",
"max_in_bytes": 50331648,
"peak_max": "48mb",
"peak_max_in_bytes": 50331648,
"peak_used": "11mb",
"peak_used_in_bytes": 11623808,
"used": "11mb",
"used_in_bytes": 11613504
},
"Par Eden Space": {
"max": "133.1mb",
"max_in_bytes": 139591680,
"peak_max": "133.1mb",
"peak_max_in_bytes": 139591680,
"peak_used": "133.1mb",
"peak_used_in_bytes": 139591680,
"used": "96.5mb",
"used_in_bytes": 101288456
},
"Par Survivor Space": {
"max": "16.6mb",
"max_in_bytes": 17432576,
"peak_max": "16.6mb",
"peak_max_in_bytes": 17432576,
"peak_used": "16.6mb",
"peak_used_in_bytes": 17432576,
"used": "741.4kb",
"used_in_bytes": 759288
}
}
},
"threads": {
"count": 348,
"peak_count": 377
},
"timestamp": 1378496012941,
"uptime": "14 hours, 25 minutes, 2 seconds and 241 milliseconds",
"uptime_in_millis": 51902241
},
"name": "Straw Man",
"network": {
"tcp": {
"active_opens": 33696,
"attempt_fails": 166,
"curr_estab": 97,
"estab_resets": 217,
"in_errs": 0,
"in_segs": 68455896,
"out_rsts": 10889,
"out_segs": 69298945,
"passive_opens": 36401,
"retrans_segs": 20613
}
},
"os": {
"cpu": {
"idle": 96,
"stolen": 0,
"sys": 1,
"user": 1
},
"load_average": [
0.0,
0.01,
0.050000000000000003
],
"mem": {
"actual_free": "6gb",
"actual_free_in_bytes": 6469910528,
"actual_used": "10.6gb",
"actual_used_in_bytes": 11444154368,
"free": "4.4gb",
"free_in_bytes": 4800462848,
"free_percent": 36,
"used": "12.2gb",
"used_in_bytes": 13113602048,
"used_percent": 63
},
"swap": {
"free": "0b",
"free_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
},
"timestamp": 1378496012939,
"uptime": "14 hours, 39 minutes and 36 seconds",
"uptime_in_millis": 52776000
},
"process": {
"cpu": {
"percent": 0,
"sys": "1 hour, 29 minutes, 23 seconds and 380 milliseconds",
"sys_in_millis": 5363380,
"total": "12 hours, 6 minutes, 25 seconds and 160 milliseconds",
"total_in_millis": 43585160,
"user": "10 hours, 37 minutes, 1 second and 780 milliseconds",
"user_in_millis": 38221780
},
"mem": {
"resident": "9.5gb",
"resident_in_bytes": 10250309632,
"share": "114mb",
"share_in_bytes": 119640064,
"total_virtual": "10.4gb",
"total_virtual_in_bytes": 11271077888
},
"open_file_descriptors": 500,
"timestamp": 1378496012939
},
"thread_pool": {
"bulk": {
"active": 0,
"completed": 400897,
"largest": 100,
"queue": 0,
"rejected": 0,
"threads": 100
},
"flush": {
"active": 0,
"completed": 1026,
"largest": 1,
"queue": 0,
"threads": 1
},
"generic": {
"active": 0,
"completed": 182321,
"largest": 7,
"queue": 0,
"rejected": 0,
"threads": 2
},
"get": {
"active": 0,
"completed": 563166,
"largest": 100,
"queue": 0,
"rejected": 0,
"threads": 100
},
"index": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"management": {
"active": 1,
"completed": 7816,
"largest": 2,
"queue": 0,
"threads": 2
},
"merge": {
"active": 0,
"completed": 230691,
"largest": 1,
"queue": 0,
"threads": 1
},
"optimize": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"percolate": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"refresh": {
"active": 0,
"completed": 207176,
"largest": 1,
"queue": 0,
"threads": 1
},
"search": {
"active": 0,
"completed": 23174840,
"largest": 100,
"queue": 0,
"rejected": 0,
"threads": 100
},
"snapshot": {
"active": 0,
"completed": 91949,
"largest": 1,
"queue": 0,
"threads": 1
},
"warmer": {
"active": 0,
"completed": 354301,
"largest": 1,
"queue": 0,
"threads": 1
}
},
"timestamp": 1378496012938,
"transport": {
"rx_count": 64202809,
"rx_size": "8.1gb",
"rx_size_in_bytes": 8780422032,
"server_open": 52,
"tx_count": 28166345,
"tx_size": "9.3gb",
"tx_size_in_bytes": 10007230919
},
"transport_address": "inet[/xxxxxxxxxxxxxxxx:9300]"
},

===============================================================================================================================================
Experiment 2: Based on the result of the previous experiment I tuned the JVM parameters in ES 0.90.3 and also used a smaller dataset 100K documents to speed up my benchmarking

DataSize: 100k documents
Total Size: 122 MB

ES Cluster Size: 3 nodes (AWS EC2 m2.xlarge instance (Memory 17.1 GB, Compute Units: 6))

of Index : 7

of shards for each index: 6

of replicas for each shard: 1

JVM parameter tuning of ES 0.90.3 ( Increased heap size, etc. It reduced GC time but not up to the point I expected):

wrapper.java.additional.1=-Delasticsearch-service
wrapper.java.additional.2=-Des.path.home=%ES_HOME%
wrapper.java.additional.3=-Xss256k
wrapper.java.additional.4=-XX:+UseParNewGC
wrapper.java.additional.5=-XX:+UseConcMarkSweepGC
wrapper.java.additional.6=-XX:CMSInitiatingOccupancyFraction=75
wrapper.java.additional.7=-XX:+UseCMSInitiatingOccupancyOnly
wrapper.java.additional.8=-XX:+HeapDumpOnOutOfMemoryError
wrapper.java.additional.9=-XX:+CMSParallelRemarkEnabled
wrapper.java.additional.10=-XX:+UseTLAB
wrapper.java.additional.11=-XX:+CMSClassUnloadingEnabled
wrapper.java.additional.12=-XX:+CMSPermGenSweepingEnabled
wrapper.java.additional.13=-Djava.awt.headless=true
wrapper.java.additional.14=-XX:MaxPermSize=%MAX_PERMGEN_MB%m
wrapper.java.additional.15=-Des.max-open-files=true

Initial Java Heap Size (in MB)

wrapper.java.initmemory=10240

Maximum Java Heap Size (in MB)

wrapper.java.maxmemory=10240

JVM settings of ES 0.20.6 is same as the previous experiment

Indexing time :

ES 0.20.6 : 47 minutes (approx)
ES 0.90.3 : 1 hr 15 minutes (approx)

Index Stat (providing info of just one node from the clusters of each version)

ES 0.20.6:

{
"cluster_name": "xxxxxxxxxxxxxxxxxxxxxxxxx",
"nodes": {
"_TgElhK5SG6ig70QgtUuWA": {
"fs": {
"data": [
{
"available": "409.3gb",
"available_in_bytes": 439545597952,
"dev": "/dev/xvdb",
"disk_read_size": "1.5mb",
"disk_read_size_in_bytes": 1627648,
"disk_reads": 437,
"disk_write_size": "8.1gb",
"disk_write_size_in_bytes": 8788468224,
"disk_writes": 230370,
"free": "409.3gb",
"free_in_bytes": 439545597952,
"total": "409.7gb",
"total_in_bytes": 439983034368
}
],
"timestamp": 1378839509732
},
"hostname": "xxxxxxxxx",
"http": {
"current_open": 3,
"total_opened": 2744
},
"indices": {
"cache": {
"bloom_size": "2.5kb",
"bloom_size_in_bytes": 2624,
"field_evictions": 0,
"field_size": "0b",
"field_size_in_bytes": 0,
"filter_count": 0,
"filter_evictions": 0,
"filter_size": "0b",
"filter_size_in_bytes": 0,
"id_cache_size": "0b",
"id_cache_size_in_bytes": 0
},
"docs": {
"count": 80170,
"deleted": 1988
},
"flush": {
"total": 114,
"total_time": "21.6s",
"total_time_in_millis": 21674
},
"get": {
"current": 0,
"exists_time": "37.5s",
"exists_time_in_millis": 37551,
"exists_total": 79338,
"missing_time": "29s",
"missing_time_in_millis": 29035,
"missing_total": 58383,
"time": "1.1m",
"time_in_millis": 66586,
"total": 137721
},
"indexing": {
"delete_current": 0,
"delete_time": "0s",
"delete_time_in_millis": 0,
"delete_total": 0,
"index_current": 0,
"index_time": "15.9m",
"index_time_in_millis": 954405,
"index_total": 99349
},
"merges": {
"current": 0,
"current_docs": 0,
"current_size": "0b",
"current_size_in_bytes": 0,
"total": 124,
"total_docs": 35300,
"total_size": "24.4mb",
"total_size_in_bytes": 25684710,
"total_time": "43.8s",
"total_time_in_millis": 43816
},
"refresh": {
"total": 143920,
"total_time": "2.2h",
"total_time_in_millis": 8158194
},
"search": {
"fetch_current": 0,
"fetch_time": "30s",
"fetch_time_in_millis": 30052,
"fetch_total": 19914,
"query_current": 0,
"query_time": "2.8h",
"query_time_in_millis": 10325711,
"query_total": 4699230
},
"store": {
"size": "331.4mb",
"size_in_bytes": 347597175,
"throttle_time": "0s",
"throttle_time_in_millis": 0
}
},
"jvm": {
"buffer_pools": {
"direct": {
"count": 569,
"total_capacity": "15.4mb",
"total_capacity_in_bytes": 16170093,
"used": "15.4mb",
"used_in_bytes": 16170093
},
"mapped": {
"count": 0,
"total_capacity": "0b",
"total_capacity_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
}
},
"gc": {
"collection_count": 2987,
"collection_time": "6 minutes, 19 seconds and 977 milliseconds",
"collection_time_in_millis": 379977,
"collectors": {
"ConcurrentMarkSweep": {
"collection_count": 6,
"collection_time": "9 seconds and 261 milliseconds",
"collection_time_in_millis": 9261
},
"ParNew": {
"collection_count": 2981,
"collection_time": "6 minutes, 10 seconds and 716 milliseconds",
"collection_time_in_millis": 370716
}
}
},
"mem": {
"heap_committed": "7.9gb",
"heap_committed_in_bytes": 8572502016,
"heap_used": "1.9gb",
"heap_used_in_bytes": 2071669064,
"non_heap_committed": "86.8mb",
"non_heap_committed_in_bytes": 91103232,
"non_heap_used": "57.1mb",
"non_heap_used_in_bytes": 59934008,
"pools": {
"CMS Old Gen": {
"max": "7.8gb",
"max_in_bytes": 8415477760,
"peak_max": "7.8gb",
"peak_max_in_bytes": 8415477760,
"peak_used": "7.8gb",
"peak_used_in_bytes": 8401194792,
"used": "1.8gb",
"used_in_bytes": 1993829920
},
"CMS Perm Gen": {
"max": "1gb",
"max_in_bytes": 1073741824,
"peak_max": "1gb",
"peak_max_in_bytes": 1073741824,
"peak_used": "44.1mb",
"peak_used_in_bytes": 46285624,
"used": "44.1mb",
"used_in_bytes": 46285624
},
"Code Cache": {
"max": "48mb",
"max_in_bytes": 50331648,
"peak_max": "48mb",
"peak_max_in_bytes": 50331648,
"peak_used": "13mb",
"peak_used_in_bytes": 13657792,
"used": "13mb",
"used_in_bytes": 13648384
},
"Par Eden Space": {
"max": "133.1mb",
"max_in_bytes": 139591680,
"peak_max": "133.1mb",
"peak_max_in_bytes": 139591680,
"peak_used": "133.1mb",
"peak_used_in_bytes": 139591680,
"used": "62.9mb",
"used_in_bytes": 66003288
},
"Par Survivor Space": {
"max": "16.6mb",
"max_in_bytes": 17432576,
"peak_max": "16.6mb",
"peak_max_in_bytes": 17432576,
"peak_used": "16.6mb",
"peak_used_in_bytes": 17432576,
"used": "11.2mb",
"used_in_bytes": 11835856
}
}
},
"threads": {
"count": 53,
"peak_count": 413
},
"timestamp": 1378839509732,
"uptime": "2 hours, 1 minute, 52 seconds and 822 milliseconds",
"uptime_in_millis": 7312822
},
"name": "Caiman",
"network": {
"tcp": {
"active_opens": 4889,
"attempt_fails": 18,
"curr_estab": 82,
"estab_resets": 39,
"in_errs": 0,
"in_segs": 14502072,
"out_rsts": 1504,
"out_segs": 14696445,
"passive_opens": 4893,
"retrans_segs": 7653
}
},
"os": {
"cpu": {
"idle": 98,
"sys": 1,
"user": 0
},
"load_average": [
0.040000000000000001,
0.029999999999999999,
1.76
],
"mem": {
"actual_free": "6.8gb",
"actual_free_in_bytes": 7397154816,
"actual_used": "9.7gb",
"actual_used_in_bytes": 10516910080,
"free": "6gb",
"free_in_bytes": 6489812992,
"free_percent": 41,
"used": "10.6gb",
"used_in_bytes": 11424251904,
"used_percent": 58
},
"swap": {
"free": "0b",
"free_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
},
"timestamp": 1378839509729,
"uptime": "2 hours, 4 minutes and 32 seconds",
"uptime_in_millis": 7472000
},
"process": {
"cpu": {
"percent": 0,
"sys": "23 minutes, 27 seconds and 670 milliseconds",
"sys_in_millis": 1407670,
"total": "1 hour, 34 minutes, 1 second and 500 milliseconds",
"total_in_millis": 5641500,
"user": "1 hour, 10 minutes, 33 seconds and 830 milliseconds",
"user_in_millis": 4233830
},
"mem": {
"resident": "9.5gb",
"resident_in_bytes": 10254131200,
"share": "114.1mb",
"share_in_bytes": 119738368,
"total_virtual": "10.4gb",
"total_virtual_in_bytes": 11231289344
},
"open_file_descriptors": 641,
"timestamp": 1378839509730
},
"thread_pool": {
"bulk": {
"active": 0,
"completed": 78193,
"largest": 30,
"queue": 0,
"rejected": 0,
"threads": 0
},
"cache": {
"active": 0,
"completed": 91637,
"largest": 4,
"queue": 0,
"threads": 1
},
"flush": {
"active": 0,
"completed": 114,
"largest": 10,
"queue": 0,
"threads": 4
},
"generic": {
"active": 0,
"completed": 14037,
"largest": 6,
"queue": 0,
"rejected": 0,
"threads": 2
},
"get": {
"active": 0,
"completed": 110380,
"largest": 20,
"queue": 0,
"rejected": 0,
"threads": 0
},
"index": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"management": {
"active": 1,
"completed": 1034,
"largest": 3,
"queue": 0,
"threads": 3
},
"merge": {
"active": 0,
"completed": 39318,
"largest": 14,
"queue": 0,
"threads": 1
},
"percolate": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"refresh": {
"active": 0,
"completed": 45668,
"largest": 10,
"queue": 0,
"threads": 1
},
"search": {
"active": 0,
"completed": 4797430,
"largest": 284,
"queue": 0,
"rejected": 0,
"threads": 1
},
"snapshot": {
"active": 0,
"completed": 13110,
"largest": 5,
"queue": 0,
"threads": 1
}
},
"timestamp": 1378839509729,
"transport": {
"rx_count": 13048268,
"rx_size": "1.7gb",
"rx_size_in_bytes": 1826332161,
"server_open": 47,
"tx_count": 6940502,
"tx_size": "1.9gb",
"tx_size_in_bytes": 2097714927
},
"transport_address": "inet[/xxxxxxxxx:9300]"
}

ES 0.90.3 :

{
"cluster_name": "xxxxxxxxxx",
"nodes": {
"5bEIQiM7QNqcwlUHP7nCJA": {
"fs": {
"data": [
{
"available": "409.4gb",
"available_in_bytes": 439677587456,
"dev": "/dev/xvdb",
"disk_read_size": "1.5mb",
"disk_read_size_in_bytes": 1639936,
"disk_reads": 440,
"disk_write_size": "16.1gb",
"disk_write_size_in_bytes": 17383471104,
"disk_writes": 498923,
"free": "409.4gb",
"free_in_bytes": 439677587456,
"total": "409.7gb",
"total_in_bytes": 439983034368
}
],
"timestamp": 1378839121916
},
"hostname": "xxxxxxx",
"http": {
"current_open": 5,
"total_opened": 3418
},
"indices": {
"docs": {
"count": 84675,
"deleted": 3008
},
"fielddata": {
"evictions": 0,
"memory_size": "2.6mb",
"memory_size_in_bytes": 2729964
},
"filter_cache": {
"evictions": 0,
"memory_size": "8.6kb",
"memory_size_in_bytes": 8896
},
"flush": {
"total": 152,
"total_time": "1.8m",
"total_time_in_millis": 110817
},
"get": {
"current": 0,
"exists_time": "1.4m",
"exists_time_in_millis": 87195,
"exists_total": 75342,
"get_time": "1.7m",
"missing_time": "19.1s",
"missing_time_in_millis": 19156,
"missing_total": 61402,
"time_in_millis": 106351,
"total": 136744
},
"id_cache": {
"memory_size": "0b",
"memory_size_in_bytes": 0
},
"indexing": {
"delete_current": 0,
"delete_time": "0s",
"delete_time_in_millis": 0,
"delete_total": 0,
"index_current": 0,
"index_time": "36.8m",
"index_time_in_millis": 2208906,
"index_total": 97192
},
"merges": {
"current": 0,
"current_docs": 0,
"current_size": "0b",
"current_size_in_bytes": 0,
"total": 7935,
"total_docs": 8925968,
"total_size": "17.4gb",
"total_size_in_bytes": 18726317481,
"total_time": "23.5h",
"total_time_in_millis": 84907064
},
"refresh": {
"total": 146975,
"total_time": "8.5h",
"total_time_in_millis": 30620105
},
"search": {
"fetch_current": 0,
"fetch_time": "45.4s",
"fetch_time_in_millis": 45409,
"fetch_total": 17271,
"open_contexts": 0,
"query_current": 0,
"query_time": "2.7h",
"query_time_in_millis": 9818367,
"query_total": 4486692
},
"store": {
"size": "201mb",
"size_in_bytes": 210776029,
"throttle_time": "5.3h",
"throttle_time_in_millis": 19215583
},
"warmer": {
"current": 0,
"total": 71727,
"total_time": "34.6m",
"total_time_in_millis": 2077566
}
},
"jvm": {
"buffer_pools": {
"direct": {
"count": 939,
"total_capacity": "19.7mb",
"total_capacity_in_bytes": 20747716,
"used": "19.7mb",
"used_in_bytes": 20747716
},
"mapped": {
"count": 0,
"total_capacity": "0b",
"total_capacity_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
}
},
"gc": {
"collection_count": 61441,
"collection_time": "1 hour, 7 minutes, 53 seconds and 232 milliseconds",
"collection_time_in_millis": 4073232,
"collectors": {
"ConcurrentMarkSweep": {
"collection_count": 86,
"collection_time": "7 seconds and 277 milliseconds",
"collection_time_in_millis": 7277
},
"ParNew": {
"collection_count": 61355,
"collection_time": "1 hour, 7 minutes, 45 seconds and 955 milliseconds",
"collection_time_in_millis": 4065955
}
}
},
"mem": {
"heap_committed": "7.9gb",
"heap_committed_in_bytes": 8583249920,
"heap_used": "413.4mb",
"heap_used_in_bytes": 433566672,
"non_heap_committed": "88.8mb",
"non_heap_committed_in_bytes": 93192192,
"non_heap_used": "57.9mb",
"non_heap_used_in_bytes": 60738288,
"pools": {
"CMS Old Gen": {
"max": "7.9gb",
"max_in_bytes": 8522825728,
"peak_max": "7.9gb",
"peak_max_in_bytes": 8522825728,
"peak_used": "7.9gb",
"peak_used_in_bytes": 8515980304,
"used": "371mb",
"used_in_bytes": 389070136
},
"CMS Perm Gen": {
"max": "1gb",
"max_in_bytes": 1073741824,
"peak_max": "1gb",
"peak_max_in_bytes": 1073741824,
"peak_used": "45.9mb",
"peak_used_in_bytes": 48160240,
"used": "45.9mb",
"used_in_bytes": 48160240
},
"Code Cache": {
"max": "48mb",
"max_in_bytes": 50331648,
"peak_max": "48mb",
"peak_max_in_bytes": 50331648,
"peak_used": "12mb",
"peak_used_in_bytes": 12605120,
"used": "11.9mb",
"used_in_bytes": 12578048
},
"Par Eden Space": {
"max": "51.2mb",
"max_in_bytes": 53739520,
"peak_max": "51.2mb",
"peak_max_in_bytes": 53739520,
"peak_used": "51.2mb",
"peak_used_in_bytes": 53739520,
"used": "36mb",
"used_in_bytes": 37811864
},
"Par Survivor Space": {
"max": "6.3mb",
"max_in_bytes": 6684672,
"peak_max": "6.3mb",
"peak_max_in_bytes": 6684672,
"peak_used": "6.3mb",
"peak_used_in_bytes": 6684672,
"used": "6.3mb",
"used_in_bytes": 6684672
}
}
},
"threads": {
"count": 948,
"peak_count": 973
},
"timestamp": 1378839121915,
"uptime": "2 hours, 34 minutes, 28 seconds and 787 milliseconds",
"uptime_in_millis": 9268787
},
"name": "Anti-Cap",
"network": {
"tcp": {
"active_opens": 7297,
"attempt_fails": 47,
"curr_estab": 94,
"estab_resets": 55,
"in_errs": 0,
"in_segs": 14752680,
"out_rsts": 2459,
"out_segs": 14638367,
"passive_opens": 7308,
"retrans_segs": 660
}
},
"os": {
"cpu": {
"idle": 99,
"stolen": 0,
"sys": 0,
"user": 0
},
"load_average": [
0.01,
1.4099999999999999,
5.2000000000000002
],
"mem": {
"actual_free": "6.7gb",
"actual_free_in_bytes": 7250518016,
"actual_used": "9.9gb",
"actual_used_in_bytes": 10663546880,
"free": "6gb",
"free_in_bytes": 6470684672,
"free_percent": 40,
"used": "10.6gb",
"used_in_bytes": 11443380224,
"used_percent": 59
},
"swap": {
"free": "0b",
"free_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
},
"timestamp": 1378839121912,
"uptime": "3 hours, 8 minutes and 35 seconds",
"uptime_in_millis": 11315000
},
"process": {
"cpu": {
"percent": 0,
"sys": "18 minutes, 43 seconds and 40 milliseconds",
"sys_in_millis": 1123040,
"total": "3 hours, 44 minutes, 47 seconds and 790 milliseconds",
"total_in_millis": 13487790,
"user": "3 hours, 26 minutes, 4 seconds and 750 milliseconds",
"user_in_millis": 12364750
},
"mem": {
"resident": "9.5gb",
"resident_in_bytes": 10241036288,
"share": "114mb",
"share_in_bytes": 119640064,
"total_virtual": "10.6gb",
"total_virtual_in_bytes": 11434696704
},
"open_file_descriptors": 491,
"timestamp": 1378839121912
},
"thread_pool": {
"bulk": {
"active": 0,
"completed": 76697,
"largest": 300,
"queue": 0,
"rejected": 0,
"threads": 300
},
"flush": {
"active": 0,
"completed": 152,
"largest": 1,
"queue": 0,
"threads": 1
},
"generic": {
"active": 0,
"completed": 41242,
"largest": 6,
"queue": 0,
"rejected": 0,
"threads": 2
},
"get": {
"active": 0,
"completed": 107900,
"largest": 300,
"queue": 0,
"rejected": 0,
"threads": 300
},
"index": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"management": {
"active": 1,
"completed": 1252,
"largest": 2,
"queue": 0,
"threads": 2
},
"merge": {
"active": 0,
"completed": 53635,
"largest": 1,
"queue": 0,
"threads": 1
},
"optimize": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"percolate": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"refresh": {
"active": 0,
"completed": 48912,
"largest": 1,
"queue": 0,
"threads": 1
},
"search": {
"active": 0,
"completed": 4511389,
"largest": 300,
"queue": 0,
"rejected": 0,
"threads": 300
},
"snapshot": {
"active": 0,
"completed": 26419,
"largest": 1,
"queue": 0,
"threads": 1
},
"warmer": {
"active": 0,
"completed": 71727,
"largest": 1,
"queue": 0,
"threads": 1
}
},
"timestamp": 1378839122688,
"transport": {
"rx_count": 12516797,
"rx_size": "1.5gb",
"rx_size_in_bytes": 1691542955,
"server_open": 52,
"tx_count": 5417689,
"tx_size": "1.8gb",
"tx_size_in_bytes": 1959543432
},
"transport_address": "inet[/xxxxxxxxx:9300]"
},

--
You received this message because you are subscribed to the Google Groups "elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an email to elasticsearch+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

--
You received this message because you are subscribed to the Google Groups "elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an email to elasticsearch+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.


(aaron) #5

I can buy that argument. For us, both write and query performance are of
interest.

It is useful to know what we should expect...i.e., write performance to
degrade w/ an upgrade to 0.90.x. It sounds like that is your experience as
well when upgrading to 0.90.

On Thursday, September 19, 2013 1:43:46 PM UTC-5, David Pilato wrote:

I did the same experience as you.
The conclusion was somehow that when you compare, you have to compare
everything.

For example:
What was your query time in 0.20 and what is it now in 0.90.

In 0.90, indexing comes with a cost but you get much more gain on query
time. This is the trade here.
Let's say that the purpose of elasticsearch is more about querying than
about storing, right? :smiley:

My 2 cents

--
David Pilato | Technical Advocate | Elasticsearch.com
@dadoonet https://twitter.com/dadoonet | @elasticsearchfrhttps://twitter.com/elasticsearchfr
| @scrutmydocs https://twitter.com/scrutmydocs

Le 18 sept. 2013 à 21:33, Ahaduzzaman Munna <ahaduzza...@gmail.com<javascript:>>
a écrit :

Summary:

Apologize at the beginning for this long post but thought it's worth
sharing the result. I did a benchmarking for the indexing time using
Elasticsearch 0.90.3 version and compared that to 0.20.6 version.
Surprisingly ES 0.90.3 performed worse than ES 0.20.6 version.
Elasticsearch has a nice API to look into index operation stats (curl
"localhost:9200/_nodes/stats?all=true") which I used to find out the reason
and found that Garbage Collection ran much much longer in ES 0.90.3 than ES
0.20.6 ( hours vs minutes). I am not sure whether this is the only reason
for ES 0.90.3 to perform worse than the previous version. So, I am seeking
experts help here providing the experiment detail for the two experiments I
carried out. If required I am willing to share the bulk operations we do
against Elasticsearch. Thank you in advance for your
thoughts/suggestions/questions.

My Questions to this forum are:
*
*
(1) Why does GC in ES 0.90.3 take longer than ES 0.20.6 version having the
same JVM setting?
(2) What can we do to improve GC time in ES 0.90.3
(3) Are there any other configurations required to improve indexing time
in ES 0.90.3 ( I know this is not a specific question but interested to
know the suggestions)

==================================================================================================================
Experiment 1: All settings are absolutely same for both ES version
clusters except increased threadpool size and queue_size in ES 0.90.3
version

*

DataSize: 500K documents
Total Size: 658 MB (approx)
ES Cluster Size: 3 nodes (AWS EC2 m2.xlarge instance (Memory 17.1 GB,
Compute Units: 6))

of Index : 7

of shards for each index: 6

of replicas for each shard: 1

JVM settings:
============
wrapper.java.additional.1=-Delasticsearch-service
wrapper.java.additional.2=-Des.path.home=%ES_HOME%
wrapper.java.additional.3=-Xss256k
wrapper.java.additional.4=-XX:+UseParNewGC
wrapper.java.additional.5=-XX:+UseConcMarkSweepGC
wrapper.java.additional.6=-XX:CMSInitiatingOccupancyFraction=75
wrapper.java.additional.7=-XX:+UseCMSInitiatingOccupancyOnly
wrapper.java.additional.8=-XX:+HeapDumpOnOutOfMemoryError
wrapper.java.additional.9=-Djava.awt.headless=true
wrapper.java.additional.10=-XX:MaxPermSize=1024m
wrapper.java.additional.11=-Des.max-open-files=true

Initial Java Heap Size (in MB)

wrapper.java.initmemory=8192

Maximum Java Heap Size (in MB)

wrapper.java.maxmemory=8192

Indexing time:
==============
ES 0.20.6 : 4 hrs 57 minutes (approx)
ES 0.90.3 : 6 hrs 12 minutes (approx)

Index Stat (providing info of just one node from the clusters of each
version)

ES 0.20.6:

{
"cluster_name": "xxxxxxxxx",
"nodes": {
"-j6dAUBySuuDU-nKt7Fyrw": {
"fs": {
"data": [
{
"available": "407.7gb",
"available_in_bytes": 437794705408,
"dev": "/dev/xvdb",
"disk_read_size": "1.5mb",
"disk_read_size_in_bytes": 1627648,
"disk_reads": 437,
"disk_write_size": "68.1gb",
"disk_write_size_in_bytes": 73151741440,
"disk_writes": 1832827,
"free": "407.7gb",
"total": "409.7gb",
"total_in_bytes": 439983034368
}
],
"timestamp": 1378496996333
},
"hostname": "xxxxxxxxxxx",
"http": {
"current_open": 4,
"total_opened": 22243
},
"indices": {
"cache": {
"bloom_size": "0b",
"bloom_size_in_bytes": 0,
"field_evictions": 0,
"field_size": "0b",
"field_size_in_bytes": 0,
"filter_count": 0,
"filter_evictions": 0,
"filter_size": "0b",
"filter_size_in_bytes": 0,
"id_cache_size": "0b",
"id_cache_size_in_bytes": 0
},
"docs": {
"count": 430122,
"deleted": 43501
},
"flush": {
"total": 1140,
"total_time": "3.6m",
"total_time_in_millis": 219575
},
"get": {
"current": 0,
"exists_time": "6.8m",
"exists_time_in_millis": 411873,
"exists_total": 449999,
"missing_time": "3.6m",
"missing_time_in_millis": 218845,
"missing_total": 311984,
"time": "10.5m",
"time_in_millis": 630718,
"total": 761983
},
"indexing": {
"delete_current": 0,
"delete_time": "0s",
"delete_time_in_millis": 0,
"delete_total": 0,
"index_current": 0,
"index_time": "2.3h",
"index_time_in_millis": 8457005,
"index_total": 557055
},
"merges": {
"current": 0,
"current_docs": 0,
"current_size": "0b",
"current_size_in_bytes": 0,
"total": 0,
"total_docs": 0,
"total_size": "0b",
"total_size_in_bytes": 0,
"total_time": "0s",
"total_time_in_millis": 0
},
"refresh": {
"total": 828303,
"total_time": "1d",
"total_time_in_millis": 94763236
},
"search": {
"fetch_current": 0,
"fetch_time": "7m",
"fetch_time_in_millis": 425956,
"fetch_total": 142283,
"query_current": 0,
"query_time": "1d",
"query_time_in_millis": 91201118,
"query_total": 24950295
},
"store": {
"size": "1.9gb",
"size_in_bytes": 2097636533,
"throttle_time": "0s",
"throttle_time_in_millis": 0
}
},
"jvm": {
"buffer_pools": {
"direct": {
"count": 722,
"total_capacity": "24.1mb",
"total_capacity_in_bytes": 25301460,
"used": "24.1mb",
"used_in_bytes": 25301460
},
"mapped": {
"count": 0,
"total_capacity": "0b",
"total_capacity_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
}
},
"gc": {
"collection_count": 20556,
"collection_time": "47 minutes, 30 seconds and 759
milliseconds",
"collection_time_in_millis": 2850759,
"collectors": {
"ConcurrentMarkSweep": {
"collection_count": 37,
"collection_time": "3 minutes, 17 seconds and
858 milliseconds",
"collection_time_in_millis": 197858
},
"ParNew": {
"collection_count": 20519,
"collection_time": "44 minutes, 12 seconds and
901 milliseconds",
"collection_time_in_millis": 2652901
}
}
},
"mem": {
"heap_committed": "7.9gb",
"heap_committed_in_bytes": 8572502016,
"heap_used": "3.8gb",
"heap_used_in_bytes": 4150505720,
"non_heap_committed": "86.8mb",
"non_heap_committed_in_bytes": 91115520,
"non_heap_used": "57mb",
"non_heap_used_in_bytes": 59847224,
"pools": {
"CMS Old Gen": {
"max": "7.8gb",
"max_in_bytes": 8415477760,
"peak_max": "7.8gb",
"peak_max_in_bytes": 8415477760,
"peak_used": "7.8gb",
"peak_used_in_bytes": 8413722272,
"used": "3.7gb",
"used_in_bytes": 4030374000
},
"CMS Perm Gen": {
"max": "1gb",
"max_in_bytes": 1073741824,
"peak_max": "1gb",
"peak_max_in_bytes": 1073741824,
"peak_used": "44.1mb",
"peak_used_in_bytes": 46268600,
"used": "44.1mb",
"used_in_bytes": 46268600
},
"Code Cache": {
"max": "48mb",
"max_in_bytes": 50331648,
"peak_max": "48mb",
"peak_max_in_bytes": 50331648,
"peak_used": "13mb",
"peak_used_in_bytes": 13705984,
"used": "12.9mb",
"used_in_bytes": 13578624
},
"Par Eden Space": {
"max": "133.1mb",
"max_in_bytes": 139591680,
"peak_max": "133.1mb",
"peak_max_in_bytes": 139591680,
"peak_used": "133.1mb",
"peak_used_in_bytes": 139591680,
"used": "113.6mb",
"used_in_bytes": 119180776
},
"Par Survivor Space": {
"max": "16.6mb",
"max_in_bytes": 17432576,
"peak_max": "16.6mb",
"peak_max_in_bytes": 17432576,
"peak_used": "16.6mb",
"peak_used_in_bytes": 17432576,
"used": "928.6kb",
"used_in_bytes": 950944
}
}
},
"threads": {
"count": 51,
"peak_count": 495
},
"timestamp": 1378496996332,
"uptime": "15 hours, 40 minutes, 8 seconds and 412
milliseconds",
"uptime_in_millis": 56408412
},
"name": "N'Garai",
"network": {
"tcp": {
"active_opens": 35069,
"attempt_fails": 17,
"curr_estab": 83,
"estab_resets": 250,
"in_errs": 0,
"in_segs": 78298021,
"out_rsts": 11407,
"out_segs": 77643508,
"passive_opens": 39077,
"retrans_segs": 73385
}
},
"os": {
"cpu": {
"idle": 98,
"sys": 0,
"user": 0
},
"load_average": [
0.16,
0.059999999999999998,
0.059999999999999998
],
"mem": {
"actual_free": "6.3gb",
"actual_free_in_bytes": 6780661760,
"actual_used": "10.3gb",
"actual_used_in_bytes": 11133403136,
"free": "3.7gb",
"free_in_bytes": 4075761664,
"free_percent": 37,
"used": "12.8gb",
"used_in_bytes": 13838303232,
"used_percent": 62
},
"swap": {
"free": "0b",
"free_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
},
"timestamp": 1378496996329,
"uptime": "15 hours, 43 minutes and 31 seconds",
"uptime_in_millis": 56611000
},
"process": {
"cpu": {
"percent": 0,
"sys": "2 hours, 17 minutes, 48 seconds and 420
milliseconds",
"sys_in_millis": 8268420,
"total": "9 hours, 54 minutes, 58 seconds and 730
milliseconds",
"total_in_millis": 35698730,
"user": "7 hours, 37 minutes, 10 seconds and 310
milliseconds",
"user_in_millis": 27430310
},
"mem": {
"resident": "9.5gb",
"resident_in_bytes": 10238775296,
"share": "114.1mb",
"share_in_bytes": 119738368,
"total_virtual": "10.4gb",
"total_virtual_in_bytes": 11256926208
},
"open_file_descriptors": 880,
"timestamp": 1378496996329
},
"thread_pool": {
"bulk": {
"active": 0,
"completed": 439949,
"largest": 36,
"queue": 0,
"rejected": 0,
"threads": 0
},
"cache": {
"active": 0,
"completed": 535929,
"largest": 4,
"queue": 0,
"threads": 1
},
"flush": {
"active": 0,
"completed": 1140,
"largest": 10,
"queue": 0,
"threads": 4
},
"generic": {
"active": 0,
"completed": 95073,
"largest": 6,
"queue": 0,
"rejected": 0,
"threads": 1
},
"get": {
"active": 0,
"completed": 614491,
"largest": 30,
"queue": 0,
"rejected": 0,
"threads": 0
},
"index": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"management": {
"active": 1,
"completed": 8605,
"largest": 3,
"queue": 0,
"threads": 3
},
"merge": {
"active": 0,
"completed": 237641,
"largest": 20,
"queue": 0,
"threads": 1
},
"percolate": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"refresh": {
"active": 0,
"completed": 269338,
"largest": 10,
"queue": 0,
"threads": 1
},
"search": {
"active": 0,
"completed": 25505973,
"largest": 332,
"queue": 0,
"rejected": 0,
"threads": 0
},
"snapshot": {
"active": 0,
"completed": 82553,
"largest": 5,
"queue": 0,
"threads": 1
}
},
"timestamp": 1378496996328,
"transport": {
"rx_count": 69348105,
"rx_size": "8.9gb",
"rx_size_in_bytes": 9630178189,
"server_open": 45,
"tx_count": 35512709,
"tx_size": "10.7gb",
"tx_size_in_bytes": 11517079589
},
"transport_address": "inet[/xxxxxxxxxxxxx:9300]"
},

ES 0.90.3 :
=========
{
"cluster_name": "xxxxxxxxxxxxxxxxxx",
"nodes": {
"9fO78qRWROK5untwFS_zjg": {
"fs": {
"data": [
{
"available": "408.6gb",
"available_in_bytes": 438829277184,
"dev": "/dev/xvdb",
"disk_read_size": "1.5mb",
"disk_read_size_in_bytes": 1635840,
"disk_reads": 439,
"disk_write_size": "99.2gb",
"disk_write_size_in_bytes": 106535511040,
"disk_writes": 2753515,
"free": "408.6gb",
"free_in_bytes": 438829277184,
"total": "409.7gb",
"total_in_bytes": 439983034368
}
],
"timestamp": 1378496012942
},
"hostname": "xxxxxxxxxxxxxxxxxxxxx",
"http": {
"current_open": 5,
"total_opened": 20503
},
"indices": {
"docs": {
"count": 439882,
"deleted": 24477
},
"fielddata": {
"evictions": 0,
"memory_size": "0b",
"memory_size_in_bytes": 0
},
"filter_cache": {
"evictions": 0,
"memory_size": "0b",
"memory_size_in_bytes": 0
},
"flush": {
"total": 1026,
"total_time": "11.3m",
"total_time_in_millis": 679732
},
"get": {
"current": 0,
"exists_time": "2.3m",
"exists_time_in_millis": 141261,
"exists_total": 395109,
"get_time": "3m",
"missing_time": "43s",
"missing_time_in_millis": 43077,
"missing_total": 316702,
"time_in_millis": 184338,
"total": 711811
},
"id_cache": {
"memory_size": "0b",
"memory_size_in_bytes": 0
},
"indexing": {
"delete_current": 0,
"delete_time": "0s",
"delete_time_in_millis": 0,
"delete_total": 0,
"index_current": 0,
"index_time": "1.3h",
"index_time_in_millis": 5019993,
"index_total": 508581
},
"merges": {
"current": 0,
"current_docs": 0,
"current_size": "0b",
"current_size_in_bytes": 0,
"total": 0,
"total_docs": 0,
"total_size": "0b",
"total_size_in_bytes": 0,
"total_time": "0s",
"total_time_in_millis": 0
},
"refresh": {
"total": 704132,
"total_time": "1.5d",
"total_time_in_millis": 135699014
},
"search": {
"fetch_current": 0,
"fetch_time": "4.9m",
"fetch_time_in_millis": 296173,
"fetch_total": 87277,
"open_contexts": 0,
"query_current": 0,
"query_time": "1.4d",
"query_time_in_millis": 122853699,
"query_total": 23079777
},
"store": {
"size": "1010mb",
"size_in_bytes": 1059109597,
"throttle_time": "1.5d",
"throttle_time_in_millis": 131598086
},
"warmer": {
"current": 0,
"total": 354301,
"total_time": "3.4h",
"total_time_in_millis": 12513103
}
},
"jvm": {
"buffer_pools": {
"direct": {
"count": 626,
"total_capacity": "32mb",
"total_capacity_in_bytes": 33558076,
"used": "32mb",
"used_in_bytes": 33558076
},
"mapped": {
"count": 0,
"total_capacity": "0b",
"total_capacity_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
}
},
"gc": {
"collection_count": 139037,
"collection_time": "2 hours, 26 minutes, 37 seconds
and 188 milliseconds",
"collection_time_in_millis": 8797188,
"collectors": {
"ConcurrentMarkSweep": {
"collection_count": 51,
"collection_time": "5 seconds and 755
milliseconds",
"collection_time_in_millis": 5755
},
"ParNew": {
"collection_count": 138986,
"collection_time": "2 hours, 26 minutes, 31
seconds and 433 milliseconds",
"collection_time_in_millis": 8791433
}
}
},
"mem": {
"heap_committed": "7.9gb",
"heap_committed_in_bytes": 8572502016,
"heap_used": "2.9gb",
"heap_used_in_bytes": 3208401136,
"non_heap_committed": "88.1mb",
"non_heap_committed_in_bytes": 92438528,
"non_heap_used": "57.1mb",
"non_heap_used_in_bytes": 59963776,
"pools": {
"CMS Old Gen": {
"max": "7.8gb",
"max_in_bytes": 8415477760,
"peak_max": "7.8gb",
"peak_max_in_bytes": 8415477760,
"peak_used": "6.9gb",
"peak_used_in_bytes": 7462132504,
"used": "2.8gb",
"used_in_bytes": 3106353392
},
"CMS Perm Gen": {
"max": "1gb",
"max_in_bytes": 1073741824,
"peak_max": "1gb",
"peak_max_in_bytes": 1073741824,
"peak_used": "46.1mb",
"peak_used_in_bytes": 48350272,
"used": "46.1mb",
"used_in_bytes": 48350272
},
"Code Cache": {
"max": "48mb",
"max_in_bytes": 50331648,
"peak_max": "48mb",
"peak_max_in_bytes": 50331648,
"peak_used": "11mb",
"peak_used_in_bytes": 11623808,
"used": "11mb",
"used_in_bytes": 11613504
},
"Par Eden Space": {
"max": "133.1mb",
"max_in_bytes": 139591680,
"peak_max": "133.1mb",
"peak_max_in_bytes": 139591680,
"peak_used": "133.1mb",
"peak_used_in_bytes": 139591680,
"used": "96.5mb",
"used_in_bytes": 101288456
},
"Par Survivor Space": {
"max": "16.6mb",
"max_in_bytes": 17432576,
"peak_max": "16.6mb",
"peak_max_in_bytes": 17432576,
"peak_used": "16.6mb",
"peak_used_in_bytes": 17432576,
"used": "741.4kb",
"used_in_bytes": 759288
}
}
},
"threads": {
"count": 348,
"peak_count": 377
},
"timestamp": 1378496012941,
"uptime": "14 hours, 25 minutes, 2 seconds and 241
milliseconds",
"uptime_in_millis": 51902241
},
"name": "Straw Man",
"network": {
"tcp": {
"active_opens": 33696,
"attempt_fails": 166,
"curr_estab": 97,
"estab_resets": 217,
"in_errs": 0,
"in_segs": 68455896,
"out_rsts": 10889,
"out_segs": 69298945,
"passive_opens": 36401,
"retrans_segs": 20613
}
},
"os": {
"cpu": {
"idle": 96,
"stolen": 0,
"sys": 1,
"user": 1
},
"load_average": [
0.0,
0.01,
0.050000000000000003
],
"mem": {
"actual_free": "6gb",
"actual_free_in_bytes": 6469910528,
"actual_used": "10.6gb",
"actual_used_in_bytes": 11444154368,
"free": "4.4gb",
"free_in_bytes": 4800462848,
"free_percent": 36,
"used": "12.2gb",
"used_in_bytes": 13113602048,
"used_percent": 63
},
"swap": {
"free": "0b",
"free_in_bytes": 0,
"used": "0b",
"used_in_bytes": 0
},
"timestamp": 1378496012939,
"uptime": "14 hours, 39 minutes and 36 seconds",
"uptime_in_millis": 52776000
},
"process": {
"cpu": {
"percent": 0,
"sys": "1 hour, 29 minutes, 23 seconds and 380
milliseconds",
"sys_in_millis": 5363380,
"total": "12 hours, 6 minutes, 25 seconds and 160
milliseconds",
"total_in_millis": 43585160,
"user": "10 hours, 37 minutes, 1 second and 780
milliseconds",
"user_in_millis": 38221780
},
"mem": {
"resident": "9.5gb",
"resident_in_bytes": 10250309632,
"share": "114mb",
"share_in_bytes": 119640064,
"total_virtual": "10.4gb",
"total_virtual_in_bytes": 11271077888
},
"open_file_descriptors": 500,
"timestamp": 1378496012939
},
"thread_pool": {
"bulk": {
"active": 0,
"completed": 400897,
"largest": 100,
"queue": 0,
"rejected": 0,
"threads": 100
},
"flush": {
"active": 0,
"completed": 1026,
"largest": 1,
"queue": 0,
"threads": 1
},
"generic": {
"active": 0,
"completed": 182321,
"largest": 7,
"queue": 0,
"rejected": 0,
"threads": 2
},
"get": {
"active": 0,
"completed": 563166,
"largest": 100,
"queue": 0,
"rejected": 0,
"threads": 100
},
"index": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"management": {
"active": 1,
"completed": 7816,
"largest": 2,
"queue": 0,
"threads": 2
},
"merge": {
"active": 0,
"completed": 230691,
"largest": 1,
"queue": 0,
"threads": 1
},
"optimize": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"percolate": {
"active": 0,
"completed": 0,
"largest": 0,
"queue": 0,
"rejected": 0,
"threads": 0
},
"refresh": {
"active": 0,
"completed": 207176,
"largest": 1,
"queue": 0,
"threads": 1
},
"search": {
"active": 0,
"completed": 23174840,
"largest": 100,
"queue": 0,
"rejected": 0,
"threads": 100
},
"snapshot": {
"active": 0,
"completed": 91949,
"largest": 1,
"queue": 0,
"threads": 1
},
"warmer": {
"active": 0,
"completed": 354301,
"largest": 1,
"queue": 0,
"threads": 1
}
},
"timestamp": 1378496012938,
"transport": {
"rx_count": 64202809,
"rx_size": "8.1gb",
"rx_size_in_bytes": 8780422032,
"server_open": 52,
"tx_count": 28166345,
"tx_size": "9.3gb",
"tx_size_in_bytes": 10007230919
},
"transport_address": "inet[/xxxxxxxxxxxxxxxx:9300]"
},

===============================================================================================================================================
Experiment 2: Based on the result of the previous experiment I tuned the
JVM parameters in ES 0.90.3 and also used a smaller dataset 100K documents
to speed up my benchmarking

================================================================================================================================================
*DataSize: *100k documents
Total Size: 122 MB

ES Cluster Size: 3 nodes (AWS EC2 m2.xlarge instance (Memory 17.1 GB,
Compute Units: 6))
*# of Index *: 7
# of shards for each index: 6
*# of replicas for each shard: *1

JVM parameter tuning of ES 0.90.3 ( Increased heap size, etc. It reduced
GC time but not up to the point I expected):

*

wrapper.java.additional.1=-Delasticsearch-service
wrapper.java.additional.2=-Des.path.home=%ES_HOME%
wrapper.java.additional.3=-Xss256k
wrapper.java.additional.4=-XX:+UseParNewGC
wrapper.java.additional.5=-XX:+UseConcMarkSweepGC
wrapper.java.additional.6=-XX:CMSInitiatingOccupancyFraction=75
wrapper.java.additional.7=-XX:+UseCMSInitiatingOccupancyOnly
wrapper.java.additional.8=-XX:+HeapDumpOnOutOfMemoryError
wrapper.java.additional.9=-XX:+CMSParallelRemarkEnabled
wrapper.java.additional.10=-XX:+UseTLAB
wrapper.java.additional.11=-XX:+CMSClassUnloadingEnabled
wrapper.java.additional.12=-XX:+CMSPermGenSweepingEnabled
wrapper.java.additional.13=-Djava.awt.headless=true
wrapper.java.additional.14=-XX:MaxPermSize=%MAX_PERMGEN_MB%m
wrapper.java.additional.15=-Des.max-open-files=true

Initial Java Heap Size (in MB)

wrapper.java.initmemory=10240

Maximum Java Heap Size (in MB)

wrapper.java.maxmemory=10240

JVM settings of ES 0.20.6 is same as the previous experiment

Indexing time :
============
ES 0.20.6 : 47 minutes (approx)
ES 0.90.3 : 1 hr 15 minutes (approx)

Index Stat (providing info of just one node from the clusters of each
version)

============================================================

ES 0.20.6:
========
{
"cluster_name": "xxxxxxxxxxxxxxxxxxxxxxxxx",
"nodes": {
"_TgElhK5SG6ig70QgtUuWA": {
"fs": {
"data": [
{
"available": "409.3gb",
"available_in_bytes": 439545597952,
"dev": "/dev/xvdb",
"disk_read_size": "1.5mb",
"disk_read_size_in_bytes": 1627648,
"disk_reads": 437,
"disk_write_size": "8.1gb",
"disk_write_size_in_bytes": 8788468224,
"disk_writes": 230370,
"free": "409.3gb",
"free_in_bytes": 439545597952,
"total": "409.7gb",
"total_in_bytes": 439983034368
}
],
"timestamp": 1378839509732
},
"hostname": "xxxxxxxxx",
"http": {
"current_open": 3,
"total_opened": 2744
},
"indices": {
"cache": {
"bloom_size": "2.5kb",
"bloom_size_in_bytes": 2624,
"field_evictions": 0,
"field_size": "0b",
"field_size_in_bytes": 0,
"filter_count": 0,
"filter_evictions": 0,
"filter_size": "0b",
"filter_size_in_bytes": 0,
"id_cache_size": "0b",
"id_cache_size_in_bytes": 0
},
"docs": {
"count": 80170,
"deleted": 1988
},
"flush": {
"total": 114,
"total_time": "21.6s",
"total_time_in_millis": 21674
},
"get": {
"current": 0,
"exists_time": "37.5s",
"exists_time_in_millis": 37551,
"exists_total": 79338,
"missing_time": "29s",
"missing_time_in_millis": 29035,
"missing_total": 58383,
"time": "1.1m",
"time_in_millis": 66586,
"total": 137721
},
"indexing": {
"delete_current": 0,
"delete_time": "0s",
"delete_time_in_millis": 0,
"delete_total": 0,
"index_current": 0,
"index_time": "15.9m",
"index_time_in_millis": 954405,
"index_total": 99349
},
"merges": {
"current": 0,
"current_docs": 0,
"current_size": "0b",
"current_size_in_bytes": 0,
"total": 124,
"total_docs": 35300,
"total_size": "24.4mb",
"total_size_in_bytes": 25684710,
"total_time": "43.8s",
"total_time_in_millis": 43816
},
"refresh": {
"total": 143920,
"total_time": "2.2h",
"total_time_in_millis": 8158194
},
"search": {
"fetch_current": 0,
"fetch_time": "30s",
"fetch_time_in_millis": 30052,
&nbs

...

--
You received this message because you are subscribed to the Google Groups "elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an email to elasticsearch+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.


(Jörg Prante) #6

No. 0.90 (Lucene 4.4) is not less performant than 0.20 (Lucene 3.6.2).

Three years ago, when Lucene 4 development started, this benchmark shows
the picture that Lucene 4 is a quantum leap in performance (and the
parallel flush of segments was a real performance boost!)

So I am very curious about what has been measured and I'm interested to
reproduce it.

For instance I would like to try a wikipedia-data bench, to find out what
is going on.

Jörg

--
You received this message because you are subscribed to the Google Groups "elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an email to elasticsearch+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.


(Jörg Prante) #7

Forgot the link:

On Thu, Sep 19, 2013 at 9:01 PM, joergprante@gmail.com <
joergprante@gmail.com> wrote:

No. 0.90 (Lucene 4.4) is not less performant than 0.20 (Lucene 3.6.2).

Three years ago, when Lucene 4 development started, this benchmark shows
the picture that Lucene 4 is a quantum leap in performance (and the
parallel flush of segments was a real performance boost!)

So I am very curious about what has been measured and I'm interested to
reproduce it.

For instance I would like to try a wikipedia-data bench, to find out what
is going on.

Jörg

--
You received this message because you are subscribed to the Google Groups "elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an email to elasticsearch+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.


(Jörg Prante) #8

And this blog post of Simon Willnauer describes the performance boost of
Lucene 4 parallel segment flush:

Jörg

--
You received this message because you are subscribed to the Google Groups "elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an email to elasticsearch+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.


(Brian Yoder) #9

My experiences were nearly the opposite: Going from 0.20.4 to 0.90.0
resulted in about 1/2 the disk space and 2/3 of the load time. And going to
0.90.3 hasn't changed it.

Do you bulk load using Java or curl / HTTP?

If the latter, then that's the issue. If the former, then:

I do it all in only Java, and use the BulkRequestBuilder as follows:

  1. Drop index refresh to 2m (per some early recommendation).
  2. Create a BulkRequestBuilder.
  3. Add up to 4096 index+delete requests (as they come in).
  4. Process them. Keep all kinds of statistics, including overall counts and
    timings, and a window every 10m. Show first N errors (if 100M failures, I
    only need to see the first 100 or so to get an idea of what went wrong).
  5. Create new BulkRequestBuilder and repeat steps 2-4.
  6. For last set of 1<=N<4096, process them.
  7. When done, put index refresh back to 1s.

I don't use the BulkProcessor because the Javadoc is pretty much not there.
It's not much better with BulkRequestBuilder, but the API is very
self-explanatory, it was easy and fun to learn by doing, and I have access
to more knobs and levers during the build.

I can't say for sure, but the increased time due to compression sure seems
to be more than made up for by the vastly smaller amount of data written to
disk. Searches are much faster too.

Using 0.90.3 on a rather slow and underpowered Linux VM, I just loaded 97
million documents in about 5 hours. Then, 1.6 million updates (even mix of
index and delete) took 7 minutes.

The same bulk load on my MacBook took 4 hours with 0.20.4 and just over 2
hours with 0.90.3.

... to provide a comparison baseline...

Brian

--
You received this message because you are subscribed to the Google Groups "elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an email to elasticsearch+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.


(Munna) #10

Thanks everyone for your input. We do use elasticsearch java client and do lots of concurrent write and read. I would like to look into what everyone suggested to follow/read and then I will get back with my findings and questions.


(system) #11