Disabled syscall filter but still issue

Elastic Stack Elasticsearch
1

I have a cluster with 10 nodes with elasticsearch 2.4 version.
I disabled in elasticsearch.yml syscall filter with this configuration:
[...]
bootstrap.system_call_filter: false
[...]
Unfortunately, elasticsearch still crash with the same problem:

[2020-05-29 10:00:10,470][INFO ][http ] [test-node3] publish_address {127.0.0.1:9201}, bound_addresses {127.0.0.1:9201}
[2020-05-29 10:00:10,471][INFO ][node ] [test-node3] started
[2020-05-29 10:20:02,086][WARN ][bootstrap ] unable to install syscall filter: seccomp unavailable: CONFIG_SECCOMP not compiled into kernel, CONFIG_SECCOMP and CONFIG_SECCOMP_FILTER are needed
[2020-05-29 10:20:02,266][INFO ][node ] [test-node3] version[2.4.2], pid[15661], build[161c65a/2016-11-17T11:51:03Z]
[2020-05-29 10:20:02,266][INFO ][node ] [test-node3] initializing ...
[2020-05-29 10:20:02,890][INFO ][plugins ] [test-node3] modules [reindex, lang-expression, lang-groovy], plugins [license, marvel-agent, delete-by-query], sites
[2020-05-29 10:20:02,915][INFO ][env ] [test-node3] using [1] data paths, mounts [[/var (/dev/mapper/vg_test)]], net usable_space [344.7gb], net total_space [1tb], spins? [possibly], types [ext4]
[2020-05-29 10:20:02,915][INFO ][env ] [test-node3] heap size [15.8gb], compressed ordinary object pointers [true]
[2020-05-29 10:20:05,892][INFO ][node ] [test-node3] initialized
[2020-05-29 10:20:05,893][INFO ][node ] [test-node3] starting ...
[2020-05-29 10:20:06,150][INFO ][transport ] [test-node3] publish_address {192.168.0.155:9500}, bound_addresses {192.168.0.155:9500}
[2020-05-29 10:20:06,157][INFO ][discovery ] [test-node3] LTMS-Security/MBU_wkDmQwuD_JdXVjq7mw
[2020-05-29 10:20:09,431][INFO ][cluster.service ] [test-node3] detected_master {test-node2}{CZwfSQvQQPqvyEiH5puhVA}{192.168.0.152}{192.168.0.152:9500}{zone=test2}, added {{test-node3}{t5L1YMgqQMaiMi9lQjVqpQ}{192.168.0.153}{192.168.0.153:9500}{zone=test1, master=false},{test-node7}{jDDL90h5SVehLcvGJ5FSzQ}{192.168.0.157}{192.168.0.157:9500}{data=false, master=true},{test-node1}{_0-gNLEcRx6uji_TLjjfYw}{192.168.0.151}{192.168.0.151:9500}{zone=test1},{test-node4}{g0WsxsNxSriGMZCSbtSCJA}{192.168.0.154}{192.168.0.154:9500}{zone=test2, master=false},{test-node9}{sZiPwdq7TwSxiqk8cFk7mg}{192.168.0.159}{192.168.0.159:9500}{data=false, master=true},{test-node2}{CZwfSQvQQPqvyEiH5puhVA}{192.168.0.152}{192.168.0.152:9500}{zone=test2},{node-balance}{0YKkXqVOTsW_NIkBnLskLg}{192.168.0.182}{192.168.0.182:9300}{data=false, master=false},{test-node8}{RbzOVzHqQuCyoFxSlZklYA}{192.168.0.158}{192.168.0.158:9500}{zone=test2, master=false},{test-node6}{yeZ8HWZbRL6OV4YqvRT0tw}{192.168.0.156}{192.168.0.156:9500}{zone=test2, master=false},}, reason: zen-disco-receive(from master [{test-node2}{CZwfSQvQQPqvyEiH5puhVA}{192.168.0.152}{192.168.0.152:9500}{zone=test2}])
[2020-05-29 10:20:09,459][INFO ][cluster ] [test-node3] updating [cluster.info.update.interval] from [30s] to [1m]
[2020-05-29 10:20:09,969][INFO ][http ] [test-node3] publish_address {127.0.0.1:9201}, bound_addresses {127.0.0.1:9201}
[2020-05-29 10:20:09,975][INFO ][node ] [test-node3] started
[2020-05-29 11:00:01,789][WARN ][bootstrap ] unable to install syscall filter: seccomp unavailable: CONFIG_SECCOMP not compiled into kernel, CONFIG_SECCOMP and CONFIG_SECCOMP_FILTER are needed
[2020-05-29 11:00:01,971][INFO ][node ] [test-node3] version[2.4.2], pid[16135], build[161c65a/2016-11-17T11:51:03Z]
[2020-05-29 11:00:01,971][INFO ][node ] [test-node3] initializing ...
[2020-05-29 11:00:02,620][INFO ][env ] [test-node3] using [1] data paths, mounts [[/var (/dev/mapper/vg_test)]], net usable_space [344.7gb], net total_space [1tb], spins? [possibly], types [ext4]
[2020-05-29 11:00:02,620][INFO ][env ] [test-node3] heap size [15.8gb], compressed ordinary object pointers [true]
[2020-05-29 11:00:05,688][INFO ][node ] [test-node3] initialized
[2020-05-29 11:00:05,688][INFO ][node ] [test-node3] starting ...

2

That logger message is just a WARN message and thus the process is not shutdown. Can you share more log messages, so far this looks like a successful start to me.

3

Thanks Alexander, after elasticsearch starts I have a lot of logs all the same of this:

[2020-06-01 09:24:24,713][DEBUG][action.bulk ] [test-node3] [test-index-2020.06.01][0] failed to execute bulk item (index) index {[test-index-2020.06.01][logs][AXJuw8H6ApG02twILe64], source[{"@version":"1","@timestamp":"2020-06-01T07:03:44.845Z","message":"logstash","in_events":{"count":24533053,"rate_1m":156.18958495016923,"rate_5m":204.12180469345148,"rate_15m":179.9485148851409},"tags":["metric"],"IP":"%{host}","collector":"logstash-collector"}]}
MapperParsingException[failed to parse [IP]]; nested: IllegalArgumentException[failed to parse ip [%{host}], not a valid ip address];
at org.elasticsearch.index.mapper.FieldMapper.parse(FieldMapper.java:329)
at org.elasticsearch.index.mapper.DocumentParser.parseObjectOrField(DocumentParser.java:311)
at org.elasticsearch.index.mapper.DocumentParser.parseAndMergeUpdate(DocumentParser.java:740)
at org.elasticsearch.index.mapper.DocumentParser.parseDynamicValue(DocumentParser.java:627)
at org.elasticsearch.index.mapper.DocumentParser.parseValue(DocumentParser.java:444)
at org.elasticsearch.index.mapper.DocumentParser.parseObject(DocumentParser.java:264)
at org.elasticsearch.index.mapper.DocumentParser.parseDocument(DocumentParser.java:124)
at org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:309)
at org.elasticsearch.index.shard.IndexShard.prepareCreate(IndexShard.java:533)
at org.elasticsearch.index.shard.IndexShard.prepareCreateOnPrimary(IndexShard.java:510)
at org.elasticsearch.action.index.TransportIndexAction.prepareIndexOperationOnPrimary(TransportIndexAction.java:214)
at org.elasticsearch.action.index.TransportIndexAction.executeIndexRequestOnPrimary(TransportIndexAction.java:223)
at org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:327)
at org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:120)
at org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:68)
at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryPhase.doRun(TransportReplicationAction.java:657)
at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)
at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:287)
at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:279)
at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:77)
at org.elasticsearch.transport.TransportService$4.doRun(TransportService.java:376)
at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.IllegalArgumentException: failed to parse ip [%{host}], not a valid ip address
at org.elasticsearch.index.mapper.ip.IpFieldMapper.ipToLong(IpFieldMapper.java:86)
at org.elasticsearch.index.mapper.ip.IpFieldMapper.innerParseCreateField(IpFieldMapper.java:357)
at org.elasticsearch.index.mapper.core.NumberFieldMapper.parseCreateField

4

I solved all mapper exceptions. Now I have this logs and after this elasticsearch process stop without others logs..

[2020-06-01 12:18:53,403][WARN ][monitor.jvm ] [test-node3] [gc][young][1012][655] duration [2.6s], collections [2]/[3.2s], total [2.6s]/[35.9s], memory [6.8gb]->[6.4gb]/[15.8gb], all_pools {[young] [460.2mb]->[7.9mb]/[865.3mb]}{[survivor] [39.8mb]->[16.3mb]/[108.1mb]}{[old] [6.3gb]->[6.4gb]/[14.9gb]}

5

so, elasticsearch starts up and is fine and there is no start up issue.

The last message against is only a WARN message, and thus not fatal or kills the process. A garbage collections happened, and it took 2.5s which is quite a bit. How often do those GCs happen?

6

From 4:00am to 10:00am these are GCs logs.

[2020-06-05 09:04:47,471][INFO ][monitor.jvm ] [test-node3] [gc][young][4062][1735] duration [721ms], collections [1]/[1.1s], total [721ms]/[1.2m], memory [6.2gb]->[5.6gb]/[15.8gb], all_pools {[young] [657.2mb]->[9.4mb]/[865.3mb]}{[survivor] [108.1mb]->[103.6mb]/[108.1mb]}{[old] [5.5gb]->[5.5gb]/[14.9gb]}
[2020-06-05 09:07:44,858][WARN ][monitor.jvm ] [test-node3] [gc][young][4238][1817] duration [1.6s], collections [1]/[2s], total [1.6s]/[1.4m], memory [6.3gb]->[5.8gb]/[15.8gb], all_pools {[young] [553.4mb]->[12.5mb]/[865.3mb]}{[survivor] [92.5mb]->[96.9mb]/[108.1mb]}{[old] [5.6gb]->[5.7gb]/[14.9gb]}
[2020-06-05 09:07:47,005][INFO ][monitor.jvm ] [test-node3] [gc][young][4240][1818] duration [945ms], collections [1]/[1.1s], total [945ms]/[1.4m], memory [6.5gb]->[5.8gb]/[15.8gb], all_pools {[young] [747.7mb]->[14.5mb]/[865.3mb]}{[survivor] [96.9mb]->[98.8mb]/[108.1mb]}{[old] [5.7gb]->[5.7gb]/[14.9gb]}
[2020-06-05 09:18:12,187][WARN ][monitor.jvm ] [test-node3] [gc][young][4855][2099] duration [2.6s], collections [1]/[3s], total [2.6s]/[1.6m], memory [6.8gb]->[6.2gb]/[15.8gb], all_pools {[young] [721.6mb]->[5.5mb]/[865.3mb]}{[survivor] [108.1mb]->[108.1mb]/[108.1mb]}{[old] [6gb]->[6gb]/[14.9gb]}
[2020-06-05 09:25:38,966][INFO ][monitor.jvm ] [test-node3] [gc][young][5176][2223] duration [920ms], collections [1]/[1.3s], total [920ms]/[1.8m], memory [7gb]->[6.9gb]/[15.8gb], all_pools {[young] [119.2mb]->[8.8mb]/[865.3mb]}{[survivor] [93.2mb]->[98mb]/[108.1mb]}{[old] [6.8gb]->[6.8gb]/[14.9gb]}
[2020-06-05 09:25:41,671][INFO ][monitor.jvm ] [test-node3] [gc][young][5178][2225] duration [1.5s], collections [2]/[1.7s], total [1.5s]/[1.8m], memory [7.6gb]->[6.9gb]/[15.8gb], all_pools {[young] [721mb]->[4.5mb]/[865.3mb]}{[survivor] [98mb]->[23.3mb]/[108.1mb]}{[old] [6.8gb]->[6.9gb]/[14.9gb]}
[2020-06-05 09:26:19,024][WARN ][monitor.jvm ] [test-node3] [gc][young][5202][2234] duration [1.2s], collections [1]/[1.9s], total [1.2s]/[1.9m], memory [7.3gb]->[7gb]/[15.8gb], all_pools {[young] [321.6mb]->[5.7mb]/[865.3mb]}{[survivor] [78.5mb]->[52.4mb]/[108.1mb]}{[old] [7gb]->[7gb]/[14.9gb]}
[2020-06-05 09:33:42,856][WARN ][monitor.jvm ] [test-node3] [gc][young][5457][2322] duration [2s], collections [1]/[2.4s], total [2s]/[2m], memory [8.1gb]->[7.6gb]/[15.8gb], all_pools {[young] [417.6mb]->[16.7mb]/[865.3mb]}{[survivor] [108.1mb]->[71.6mb]/[108.1mb]}{[old] [7.5gb]->[7.6gb]/[14.9gb]}
[2020-06-05 09:52:49,982][WARN ][monitor.jvm ] [test-node3] [gc][young][6337][2745] duration [2.3s], collections [2]/[2.7s], total [2.3s]/[2.5m], memory [10.7gb]->[10.6gb]/[15.8gb], all_pools {[young] [271.9mb]->[126mb]/[865.3mb]}{[survivor] [108.1mb]->[44.7mb]/[108.1mb]}{[old] [10.4gb]->[10.4gb]/[14.9gb]}

These are started logs. I use a simple script to restart node when go down.

[2020-06-05 04:15:10,205][INFO ][node ] [test-node3] started
[2020-06-05 04:35:10,449][INFO ][node ] [test-node3] started
[2020-06-05 04:50:10,020][INFO ][node ] [test-node3] started
[2020-06-05 05:05:09,501][INFO ][node ] [test-node3] started
[2020-06-05 05:25:10,234][INFO ][node ] [test-node3] started
[2020-06-05 05:40:09,880][INFO ][node ] [test-node3] started
[2020-06-05 05:55:09,633][INFO ][node ] [test-node3] started
[2020-06-05 06:15:10,413][INFO ][node ] [test-node3] started
[2020-06-05 06:30:09,845][INFO ][node ] [test-node3] started
[2020-06-05 06:45:09,352][INFO ][node ] [test-node3] started
[2020-06-05 07:00:11,255][INFO ][node ] [test-node3] started
[2020-06-05 07:15:09,468][INFO ][node ] [test-node3] started
[2020-06-05 07:35:10,267][INFO ][node ] [test-node3] started
[2020-06-05 07:55:10,335][INFO ][node ] [test-node3] started

7

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.