Log4j Vulnerability: JVM Options not picked from location mentioned in %ES_PATH_CONF%

Does anyone know why setting option -Dlog4j2.formatMsgNoLookups=true in jvm.options file does not work?

Elasticsearch version (bin/elasticsearch --version): 7.5.1

Plugins installed: None

JVM version (java -version): 13.0.1

OS version (uname -a if on a Unix-like system): Windows Server 2012 R2 Standard

Description of the problem including expected versus actual behaviour:
Our ES cluster has 3 nodes each running v7.5.1. For latest log4j CVE-2021-44228 vulnerability, we are putting -Dlog4j2.formatMsgNoLookups=true on our nodes in %ES_PATH_CONF% as mentioned here. The value is D:\Data\config & a jvm file located at D:\Data\config\elasticsearch\jvm.options in which following changes are made.

Actual behaviour
The node is restarted but upon seeing in http://<node_server>:9200/_nodes/jvm?pretty the input_arguments are not picked. They remain the same as before even though the value of Des.path.conf in the URL is the same as where we made the changes.

Expected behaviour
If we make any changes to jvm.options file mentioned in %ES_PATH_CONF%, then the changes should be reflected when the ES node comes up.

Steps to reproduce:
Add -Dlog4j2.formatMsgNoLookups=true in jvm.options file mentioned in %ES_PATH_CONF% and restart node.

Provide logs (if relevant):

[2021-12-20T05:58:45,100][INFO ][o.e.e.NodeEnvironment    ] [LS88] using [1] data paths, mounts [[LS88_D (D:)]], net usable_space [75.2gb], net total_space [409.9gb], types [NTFS]
[2021-12-20T05:58:45,105][INFO ][o.e.e.NodeEnvironment    ] [LS88] heap size [11.8gb], compressed ordinary object pointers [true]
[2021-12-20T05:58:46,884][INFO ][o.e.n.Node               ] [LS88] node name [LS88], node ID [6ADF9wRYQCWzGtOTebOQZA], cluster name [fluid]
[2021-12-20T05:58:46,885][INFO ][o.e.n.Node               ] [LS88] version[7.5.1], pid[94696], build[default/zip/3ae9ac9a93c95bd0cdc054951cf95d88e1e18d96/2019-12-16T22:57:37.835892Z], OS[Windows Server 2012 R2/6.3/amd64], JVM[AdoptOpenJDK/OpenJDK 64-Bit Server VM/13.0.1/13.0.1+9]
[2021-12-20T05:58:46,886][INFO ][o.e.n.Node               ] [LS88] JVM home [D:\Octopus\Applications\UAT\elasticsearch\7.5.1\elasticsearch-7.5.1\jdk]
[2021-12-20T05:58:46,886][INFO ][o.e.n.Node               ] [LS88] JVM arguments [-Des.networkaddress.cache.ttl=60, -Des.networkaddress.cache.negative.ttl=10, -XX:+AlwaysPreTouch, -Xss1m, -Djava.awt.headless=true, -Dfile.encoding=UTF-8, -Djna.nosys=true, -XX:-OmitStackTraceInFastThrow, -Dio.netty.noUnsafe=true, -Dio.netty.noKeySetOptimization=true, -Dio.netty.recycler.maxCapacityPerThread=0, -Dio.netty.allocator.numDirectArenas=0, -Dlog4j.shutdownHookEnabled=false, -Dlog4j2.disable.jmx=true, -Djava.locale.providers=COMPAT, -Xms12g, -Xmx12g, -XX:+UseConcMarkSweepGC, -XX:CMSInitiatingOccupancyFraction=75, -XX:+UseCMSInitiatingOccupancyOnly, -Des.networkaddress.cache.ttl=60, -Des.networkaddress.cache.negative.ttl=10, -XX:+AlwaysPreTouch, -Xss1m, -Djava.awt.headless=true, -Dfile.encoding=UTF-8, -Djna.nosys=true, -XX:-OmitStackTraceInFastThrow, -Dio.netty.noUnsafe=true, -Dio.netty.noKeySetOptimization=true, -Dio.netty.recycler.maxCapacityPerThread=0, -Dlog4j.shutdownHookEnabled=false, -Dlog4j2.disable.jmx=true, -Djava.io.tmpdir=D:\Data\elasticsearch\temp, -XX:+HeapDumpOnOutOfMemoryError, -XX:HeapDumpPath=D:\Data\elasticsearch, -XX:ErrorFile=D:\Data\Logs\elasticsearch\hs_err_pid%p.log, -Xlog:gc*,gc+age=trace,safepoint:file=D:\Data\Logs\elasticsearch\gc.log:utctime,pid,tags:filecount=32,filesize=64m, -Djava.locale.providers=COMPAT, -XX:UseAVX=2, -XX:MaxDirectMemorySize=6442450944, -Delasticsearch, -Des.path.home=D:\Octopus\Applications\UAT\elasticsearch\7.5.1\elasticsearch-7.5.1, -Des.path.conf=D:\data\Config\elasticsearch, -Des.distribution.flavor=default, -Des.distribution.type=zip, -Des.bundled_jdk=true, exit, abort, -Xms12288m, -Xmx12288m, -Xss1024k]
[2021-12-20T05:58:49,206][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [aggs-matrix-stats]
[2021-12-20T05:58:49,207][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [analysis-common]
[2021-12-20T05:58:49,207][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [flattened]
[2021-12-20T05:58:49,207][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [frozen-indices]
[2021-12-20T05:58:49,207][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [ingest-common]
[2021-12-20T05:58:49,207][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [ingest-geoip]
[2021-12-20T05:58:49,207][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [ingest-user-agent]
[2021-12-20T05:58:49,208][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [lang-expression]
[2021-12-20T05:58:49,208][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [lang-mustache]
[2021-12-20T05:58:49,208][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [lang-painless]
[2021-12-20T05:58:49,208][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [mapper-extras]
[2021-12-20T05:58:49,208][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [parent-join]
[2021-12-20T05:58:49,209][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [percolator]
[2021-12-20T05:58:49,209][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [rank-eval]
[2021-12-20T05:58:49,209][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [reindex]
[2021-12-20T05:58:49,209][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [repository-url]
[2021-12-20T05:58:49,209][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [search-business-rules]
[2021-12-20T05:58:49,209][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [spatial]
[2021-12-20T05:58:49,210][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [transform]
[2021-12-20T05:58:49,210][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [transport-netty4]
[2021-12-20T05:58:49,210][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [vectors]
[2021-12-20T05:58:49,210][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [x-pack-analytics]
[2021-12-20T05:58:49,210][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [x-pack-ccr]
[2021-12-20T05:58:49,210][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [x-pack-core]
[2021-12-20T05:58:49,211][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [x-pack-deprecation]
[2021-12-20T05:58:49,211][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [x-pack-enrich]
[2021-12-20T05:58:49,211][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [x-pack-graph]
[2021-12-20T05:58:49,211][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [x-pack-ilm]
[2021-12-20T05:58:49,211][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [x-pack-logstash]
[2021-12-20T05:58:49,211][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [x-pack-ml]
[2021-12-20T05:58:49,212][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [x-pack-monitoring]
[2021-12-20T05:58:49,212][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [x-pack-rollup]
[2021-12-20T05:58:49,212][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [x-pack-security]
[2021-12-20T05:58:49,212][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [x-pack-sql]
[2021-12-20T05:58:49,212][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [x-pack-voting-only-node]
[2021-12-20T05:58:49,212][INFO ][o.e.p.PluginsService     ] [LS88] loaded module [x-pack-watcher]
[2021-12-20T05:58:49,213][INFO ][o.e.p.PluginsService     ] [LS88] no plugins loaded
[2021-12-20T05:58:53,310][INFO ][o.e.x.m.p.l.CppLogMessageHandler] [LS88] [controller/89388] [Main.cc@110] controller (64 bit): Version 7.5.1 (Build ae3c3c51b849be) Copyright (c) 2019 Elasticsearch BV
[2021-12-20T05:58:54,045][INFO ][o.e.d.DiscoveryModule    ] [LS88] using discovery type [zen] and seed hosts providers [settings]
[2021-12-20T05:58:54,951][INFO ][o.e.n.Node               ] [LS88] initialized
[2021-12-20T05:58:54,951][INFO ][o.e.n.Node               ] [LS88] starting ...
[2021-12-20T05:58:55,364][INFO ][o.e.t.TransportService   ] [LS88] publish_address {11.182.228.102:9300}, bound_addresses {[::]:9300}
[2021-12-20T05:58:57,812][INFO ][o.e.b.BootstrapChecks    ] [LS88] bound or publishing to a non-loopback address, enforcing bootstrap checks
[2021-12-20T05:58:57,815][INFO ][o.e.c.c.Coordinator      ] [LS88] cluster UUID [Wu41VmjNSTmG5lIPpb4FZg]
[2021-12-20T05:58:58,436][INFO ][o.e.c.s.ClusterApplierService] [LS88] master node changed {previous [], current [{LS89}{4Pb5o77jRgKR4aefJtU4Tw}{rm51xVDWTu-__b-vA_hQUg}{11.182.228.103}{11.182.228.103:9300}{dilm}{ml.machine_memory=68719009792, ml.max_open_jobs=20, xpack.installed=true}]}, added {{LS89}{4Pb5o77jRgKR4aefJtU4Tw}{rm51xVDWTu-__b-vA_hQUg}{11.182.228.103}{11.182.228.103:9300}{dilm}{ml.machine_memory=68719009792, ml.max_open_jobs=20, xpack.installed=true},{LS95}{9JajKLZ7RzqFsdTf0xYOBw}{51oSI7qaR9ucq1aL9tQNRw}{11.182.230.234}{11.182.230.234:9300}{dilm}{ml.machine_memory=34359267328, ml.max_open_jobs=20, xpack.installed=true}}, term: 516, version: 52607008, reason: ApplyCommitRequest{term=516, version=52607008, sourceNode={LS89}{4Pb5o77jRgKR4aefJtU4Tw}{rm51xVDWTu-__b-vA_hQUg}{11.182.228.103}{11.182.228.103:9300}{dilm}{ml.machine_memory=68719009792, ml.max_open_jobs=20, xpack.installed=true}}
[2021-12-20T05:58:58,466][INFO ][o.e.c.s.ClusterSettings  ] [LS88] updating [cluster.info.update.interval] from [30s] to [1m]
[2021-12-20T05:58:58,467][INFO ][o.e.c.s.ClusterSettings  ] [LS88] updating [cluster.routing.allocation.disk.watermark.low] from [85%] to [30gb]
[2021-12-20T05:58:58,467][INFO ][o.e.c.s.ClusterSettings  ] [LS88] updating [cluster.routing.allocation.disk.watermark.high] from [90%] to [20gb]
[2021-12-20T05:58:58,467][INFO ][o.e.c.s.ClusterSettings  ] [LS88] updating [cluster.routing.allocation.disk.watermark.flood_stage] from [95%] to [10gb]
[2021-12-20T05:58:58,467][INFO ][o.e.c.s.ClusterSettings  ] [LS88] updating [cluster.routing.allocation.node_concurrent_incoming_recoveries] from [2] to [6]
[2021-12-20T05:58:58,467][INFO ][o.e.c.s.ClusterSettings  ] [LS88] updating [cluster.routing.allocation.node_concurrent_outgoing_recoveries] from [2] to [6]
[2021-12-20T05:58:58,468][INFO ][o.e.c.s.ClusterSettings  ] [LS88] updating [xpack.monitoring.collection.enabled] from [false] to [true]
[2021-12-20T05:58:58,468][INFO ][o.e.c.s.ClusterSettings  ] [LS88] updating [cluster.routing.allocation.disk.watermark.low] from [85%] to [30gb]
[2021-12-20T05:58:58,468][INFO ][o.e.c.s.ClusterSettings  ] [LS88] updating [cluster.routing.allocation.disk.watermark.high] from [90%] to [20gb]
[2021-12-20T05:58:58,469][INFO ][o.e.c.s.ClusterSettings  ] [LS88] updating [cluster.routing.allocation.disk.watermark.flood_stage] from [95%] to [10gb]
[2021-12-20T05:58:59,457][INFO ][o.e.l.LicenseService     ] [LS88] license [0df6a542-c8d3-4b9b-919c-898eb7e18b6b] mode [basic] - valid
[2021-12-20T05:58:59,558][INFO ][o.e.h.AbstractHttpServerTransport] [LS88] publish_address {11.182.228.102:9200}, bound_addresses {[::]:9200}
[2021-12-20T05:58:59,559][INFO ][o.e.n.Node               ] [LS88] started
[2021-12-20T05:59:01,595][INFO ][o.e.x.w.WatcherService   ] [LS88] reloading watcher, reason [new local watcher shard allocation ids], cancelled [0] queued tasks

Welcome to our community! :smiley:

I wanted to note that 7.5 is EOL and no longer supported. I hope someone else can stop in and provide you a bit of advice for this version and issue, but you may have to upgrade to get a solution anyway.

Thanks Mark.

We were finally able to resolve this by making changes in registry at
HKEY_LOCAL_MACHINE\SOFTWARE\Wow6432Node\Apache Software Foundation\Procrun 2.0\Elasticsearch\Parameters\Java

Here's an Options multi-line entry where adding the setting and restarting ES windows service worked.

I couldn't find any documentation for this on ES docs. Would be helpful if someone finds it and share its link here.

Cheers,
Nikhil

GitHub Link for same.

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