[BUG] sudo systemctl start opensearch failed to start

[stefanoDev97]

Describe the bug
I'm trying to start opensearch on amazon 2 linux-x64.rpm using sudo systemctl start opensearch, but I'm getting this error : Job for opensearch.service failed because the control process exited with error code. See "systemctl status opensearch.service" and "journalctl -xe" for details.

Expected behavior
The cmd should start the opensearch service

Screenshots

Host/Environment:

• OS: Amazon Linux 2 AMI

Additional context

Oct 07 12:00:43 ip-000-00-00-000.eu-central-1.compute.internal systemd[1]: Started Run the CVE-2021-44228 hotfix script.
-- Subject: Unit log4j-cve-2021-44228-hotpatch.service has finished start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit log4j-cve-2021-44228-hotpatch.service has finished starting up.
--
-- The start-up result is done.
Oct 07 12:00:43 ip-000-00-00-000.eu-central-1.compute.internal log4j-cve-2021-44228-hotpatch[2765]: [log4j-hotpatch] Starting up now...
Oct 07 12:00:43 ip-000-00-00-000.eu-central-1.compute.internal root[2766]: Starting up now...
Oct 07 12:00:43 ip-000-00-00-000.eu-central-1.compute.internal log4j-cve-2021-44228-hotpatch[2765]: [log4j-hotpatch] Found JVMs with pids [2751]
Oct 07 12:00:43 ip-000-00-00-000.eu-central-1.compute.internal root[2775]: Found JVMs with pids [2751]
Oct 07 12:00:43 ip-000-00-00-000.eu-central-1.compute.internal log4j-cve-2021-44228-hotpatch[2765]: [log4j-hotpatch] Attempting to patch 2751
Oct 07 12:00:43 ip-000-00-00-000.eu-central-1.compute.internal root[2777]: Attempting to patch 2751
Oct 07 12:00:43 ip-000-00-00-000.eu-central-1.compute.internal log4j-cve-2021-44228-hotpatch[2765]: cat: /proc/2751/stat: No such file or directory
Oct 07 12:00:43 ip-000-00-00-000.eu-central-1.compute.internal log4j-cve-2021-44228-hotpatch[2765]: [log4j-hotpatch] Process pid 2751 no longer a java process, skipping.
Oct 07 12:00:43 ip-000-00-00-000.eu-central-1.compute.internal root[2799]: Process pid 2751 no longer a java process, skipping.
Oct 07 12:00:46 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: WARNING: A terminally deprecated method in java.lang.System has been called
Oct 07 12:00:46 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: WARNING: System::setSecurityManager has been called by org.opensearch.bootstrap.OpenSearch (file:/usr/share/opensearch/lib/opensearch-2.6.0.jar)
Oct 07 12:00:46 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: WARNING: Please consider reporting this to the maintainers of org.opensearch.bootstrap.OpenSearch
Oct 07 12:00:46 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: WARNING: System::setSecurityManager will be removed in a future release
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: Exception in thread "main" java.lang.NoSuchMethodError: 'java.util.Map org.apache.logging.log4j.util.PropertiesUtil.partitionOnCommonPrefixes(java.util.Properties, boolean)'
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: at org.apache.logging.log4j.core.config.properties.PropertiesConfigurationBuilder.build(PropertiesConfigurationBuilder.java:176)
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: at org.opensearch.common.logging.LogConfigurator$2.getConfiguration(LogConfigurator.java:233)
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: at org.opensearch.common.logging.LogConfigurator$2.getConfiguration(LogConfigurator.java:202)
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: at org.apache.logging.log4j.core.config.ConfigurationFactory.getConfiguration(ConfigurationFactory.java:297)
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: at org.opensearch.common.logging.LogConfigurator$3.visitFile(LogConfigurator.java:241)
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: at org.opensearch.common.logging.LogConfigurator$3.visitFile(LogConfigurator.java:237)
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: at java.base/java.nio.file.Files.walkFileTree(Files.java:2811)
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: at org.opensearch.common.logging.LogConfigurator.configure(LogConfigurator.java:237)
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: at org.opensearch.common.logging.LogConfigurator.configure(LogConfigurator.java:147)
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: at org.opensearch.bootstrap.Bootstrap.init(Bootstrap.java:373)
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: at org.opensearch.bootstrap.OpenSearch.init(OpenSearch.java:180)
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: at org.opensearch.bootstrap.OpenSearch.execute(OpenSearch.java:171)
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: at org.opensearch.cli.EnvironmentAwareCommand.execute(EnvironmentAwareCommand.java:104)
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: at org.opensearch.cli.Command.mainWithoutErrorHandling(Command.java:138)
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: at org.opensearch.cli.Command.main(Command.java:101)
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: at org.opensearch.bootstrap.OpenSearch.main(OpenSearch.java:137)
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd-entrypoint[2674]: at org.opensearch.bootstrap.OpenSearch.main(OpenSearch.java:103)
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd[1]: opensearch.service: main process exited, code=exited, status=1/FAILURE
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd[1]: Failed to start OpenSearch.
-- Subject: Unit opensearch.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit opensearch.service has failed.
--
-- The result is failed.
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd[1]: Unit opensearch.service entered failed state.
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal systemd[1]: opensearch.service failed.
Oct 07 12:00:48 ip-000-00-00-000.eu-central-1.compute.internal sudo[2670]: pam_unix(sudo:session): session closed for user root
Oct 07 12:00:53 ip-000-00-00-000.eu-central-1.compute.internal systemd[1]: log4j-cve-2021-44228-hotpatch.service holdoff time over, scheduling restart.
Oct 07 12:00:53 ip-000-00-00-000.eu-central-1.compute.internal systemd[1]: Stopped Run the CVE-2021-44228 hotfix script.
-- Subject: Unit log4j-cve-2021-44228-hotpatch.service has finished shutting down
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit log4j-cve-2021-44228-hotpatch.service has finished shutting down.
Oct 07 12:00:53 ip-000-00-00-000.eu-central-1.compute.internal systemd[1]: Started Run the CVE-2021-44228 hotfix script.
-- Subject: Unit log4j-cve-2021-44228-hotpatch.service has finished start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit log4j-cve-2021-44228-hotpatch.service has finished starting up.

I would be grateful for any help.
Thnk you

[msfroh]

@stefanoDev97 -- Can you provide more details on how you installed OpenSearch?

In particular, that lo4j-cve-2021-44228-hotpatch should no longer be needed.

That was a hot-patch to address the major log4j vulnerability (from 2021, I suppose), and has since been resolved by upgrading Log4J. In particular, it shouldn't be needed for OpenSearch 2.6.

[Saikumar282]

Facing same issue with but logs are saying different

-- Subject: Unit opensearch.service has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit opensearch.service has begun starting up.
Jan 09 07:22:42 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: [0.025s][info][gc] Using G1
Jan 09 07:22:46 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: WARNING: A terminally deprecated method in java.lang.System has been called
Jan 09 07:22:46 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: WARNING: System::setSecurityManager has been called by org.opensearch.bootstra
Jan 09 07:22:46 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: WARNING: Please consider reporting this to the maintainers of org.opensearch.b
Jan 09 07:22:46 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: WARNING: System::setSecurityManager will be removed in a future release
Jan 09 07:22:49 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: WARNING: A terminally deprecated method in java.lang.System has been called
Jan 09 07:22:49 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: WARNING: System::setSecurityManager has been called by org.opensearch.bootstra
Jan 09 07:22:49 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: WARNING: Please consider reporting this to the maintainers of org.opensearch.b
Jan 09 07:22:49 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: WARNING: System::setSecurityManager will be removed in a future release
Jan 09 07:22:51 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: [8.284s][info][gc] GC(0) Pause Young (Concurrent Start) (Metadata GC Threshold
Jan 09 07:22:51 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: [8.284s][info][gc] GC(1) Concurrent Mark Cycle
Jan 09 07:22:51 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: [8.300s][info][gc] GC(1) Pause Remark 30M->30M(15688M) 3.375ms
Jan 09 07:22:51 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: [8.300s][info][gc] GC(1) Pause Cleanup 30M->30M(15688M) 0.027ms
Jan 09 07:22:51 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: [8.353s][info][gc] GC(1) Concurrent Mark Cycle 68.983ms
Jan 09 07:22:52 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: [10.050s][info][gc] GC(2) Pause Young (Concurrent Start) (Metadata GC Threshol
Jan 09 07:22:52 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: [10.050s][info][gc] GC(3) Concurrent Mark Cycle
Jan 09 07:22:53 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: [10.067s][info][gc] GC(3) Pause Remark 42M->42M(15688M) 3.266ms
Jan 09 07:22:53 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: [10.067s][info][gc] GC(3) Pause Cleanup 42M->42M(15688M) 0.027ms
Jan 09 07:22:53 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: [10.122s][info][gc] GC(3) Concurrent Mark Cycle 71.526ms
Jan 09 07:22:55 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: [12.988s][info][gc] GC(4) Pause Young (Concurrent Start) (Metadata GC Threshol
Jan 09 07:22:55 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: [12.988s][info][gc] GC(5) Concurrent Mark Cycle
Jan 09 07:22:55 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: [13.042s][info][gc] GC(5) Pause Remark 76M->76M(15688M) 4.144ms
Jan 09 07:22:55 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: [13.046s][info][gc] GC(5) Pause Cleanup 76M->76M(15688M) 0.038ms
Jan 09 07:22:56 ip-00.00.00.00.region.compute.internal systemd-entrypoint[2971]: [13.100s][info][gc] GC(5) Concurrent Mark Cycle 112.020ms
Jan 09 07:23:15 ip-00.00.00.00.region.compute.internal polkitd[2638]: Unregistered Authentication Agent for unix-process:2965:187912 (system bus name :1.158, o
Jan 09 07:23:18 ip-00.00.00.00.region.compute.internal dhclient[3435]: XMT: Solicit on eth0, interval 120100ms.
Jan 09 07:23:52 ip-00.00.00.00.region.compute.internal systemd[1]: opensearch.service start operation timed out. Terminating.
Jan 09 07:23:53 ip-00.00.00.00.region.compute.internal systemd[1]: Failed to start OpenSearch.
-- Subject: Unit opensearch.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit opensearch.service has failed.
--
-- The result is failed.
Jan 09 07:23:53 ip-00.00.00.00.region.compute.internal systemd[1]: Unit opensearch.service entered failed state.
Jan 09 07:23:53 ip-00.00.00.00.region.compute.internal systemd[1]: opensearch.service failed.

[andrross]

[Triage - attendees 1 2 3]
@stefanoDev97 Thanks for filing the issue. I don't see an obvious bug here with the OpenSearch distribution. I encourage you to reach out on the forum or slack for help with your setup.