Error logs found in wazuh-indexer in demo environment

[juliamagan]

Wazuh version	Install type	Platform
v4.3.0-rc6	Wazuh Indexer	Demo environment

During the investigation at wazuh/wazuh-qa#2819, we found some unexpected logs on all machines with wazuh-indexer:

• journalctl -xe -u wazuh-indexer.service

abr 24 05:20:54 ip-10-0-2-167.us-west-1.compute.internal systemd-entrypoint[17699]: Exception in thread "Attach Listener" Agent failed to start!

• egrep -i "ERROR|WARNING| /var/log/wazuh-indexer/wazuh.log

[2022-04-25T00:43:22,056][ERROR][o.o.s.s.h.n.SecuritySSLNettyHttpServerTransport] [node-1] Exception during establishing a SSL connection: java.net.SocketException: Connection reset
[2022-04-25T00:43:22,256][ERROR][o.o.s.s.h.n.SecuritySSLNettyHttpServerTransport] [node-1] Exception during establishing a SSL connection: javax.net.ssl.SSLHandshakeException: no cipher suites in common
[2022-04-25T00:43:22,826][ERROR][o.o.s.s.h.n.SecuritySSLNettyHttpServerTransport] [node-1] Exception during establishing a SSL connection: java.net.SocketException: Connection reset
[2022-04-25T01:06:46,960][ERROR][o.o.s.s.h.n.SecuritySSLNettyHttpServerTransport] [node-1] Exception during establishing a SSL connection: io.netty.handler.ssl.NotSslRecordException: not an SSL/TLS record: 474554202f20485454502f312e310d0a486f73743a2035342e3137372e37362e37373a393230300d0a557365722d4167656e743a204d6f7a696c6c612f352e302028636f6d70617469626c653b2043656e737973496e73706563742f312e313b202b68747470733a2f2f61626f75742e63656e7379732e696f2f290d0a4163636570743a202a2f2a0d0a4163636570742d456e636f64696e673a20677a69700d0a0d0a

[fcaffieri]

Update report

I continue to investigate the following error: SSL connection: io.netty.handler.ssl.NotSslRecordException: not an SSL/TLS record.
So far I found the following points as possible causes:

• Certificate problem, this would not be feasible since they are generated with the installation.
• HTTP vs HTTPS mismatch: this would not make much sense, since in the configuration the protocol is always HTTPS.
• Got some residual indices with "red" status: Check the demo environments and the indices are correct and green
• The reason is that when you access opendistro with default configuration, you need to disable demo certificates(by setting environment DISABLE_INSTALL_DEMO_CONFIG to true) and then replace them with your own: the same, the cert and the config are generated automatically and should not be an issue.

I checked the indexer, dashboard, and manager nodes of the demo environment and I didn't see anything weird, just those errors in the logs.
I also checked the pipeline log that raised the demos on 04/18, but they are ok.

[alberpilot]

This issue needs to be completed by explaining all logs found. I move it from In review to Todo.

[verdx]

The second error, gotten with egrep -i "ERROR|WARNING| /var/log/wazuh-indexer/wazuh.log:

[2022-04-25T00:43:22,056][ERROR][o.o.s.s.h.n.SecuritySSLNettyHttpServerTransport] [node-1] Exception during establishing a SSL connection: java.net.SocketException: Connection reset
[2022-04-25T00:43:22,256][ERROR][o.o.s.s.h.n.SecuritySSLNettyHttpServerTransport] [node-1] Exception during establishing a SSL connection: javax.net.ssl.SSLHandshakeException: no cipher suites in common
[2022-04-25T00:43:22,826][ERROR][o.o.s.s.h.n.SecuritySSLNettyHttpServerTransport] [node-1] Exception during establishing a SSL connection: java.net.SocketException: Connection reset
[2022-04-25T01:06:46,960][ERROR][o.o.s.s.h.n.SecuritySSLNettyHttpServerTransport] [node-1] Exception during establishing a SSL connection: io.netty.handler.ssl.NotSslRecordException: not an SSL/TLS record: 474554202f20485454502f312e310d0a486f73743a2035342e3137372e37362e37373a393230300d0a557365722d4167656e743a204d6f7a696c6c612f352e302028636f6d70617469626c653b2043656e737973496e73706563742f312e313b202b68747470733a2f2f61626f75742e63656e7379732e696f2f290d0a4163636570743a202a2f2a0d0a4163636570742d456e636f64696e673a20677a69700d0a0d0a

seems to come from a protocol error, as the received SSL/TLS record is really an HTTP request sent from another host in the cluster. The last gibberish is the hexadecimal version of ASCII for:

GET / HTTP/1.1
Host: 54.177.76.77:9200
User-Agent: Mozilla/5.0 (compatible; CensysInspect/1.1; +https://about.censys.io/)
Accept: */*
Accept-Encoding: gzip

On the first error, this are some links that may have some interesting information:
https://stackoverflow.com/questions/8224844/understanding-jvms-attach-listener-thread
invesdwin/invesdwin-instrument#21

[verdx]

The GET Request that gave the error to the indexer, which was expecting an SSL/TLS record, was sent by Censys.io. This system does automatic scans of all IPs on the internet. One of the requests it sends for the scan got into the Socket opened to connect with clients. The error doesn't have anything to do with Wazuh and doesn't seem a problem, except for its confusing nature.

To opt out of this specific web, the firewall must be configured to drop traffic from their IPs, as seen here:
https://support.censys.io/hc/en-us/articles/360043177092-Opt-Out-of-Data-Collection

After seeing in the full logs written in issue wazuh/wazuh-qa#2819, where this issue comes from, there seem to be more services with automatic scans that also produce SSL/TLS errors:

[2022-04-25T03:23:07,637][ERROR][o.o.s.s.h.n.SecuritySSLNettyHttpServerTransport] [node-1] Exception during establishing a SSL connection: io.netty.handler.ssl.NotSslRecordException: not an SSL/TLS record: 474554202f20485454502f312e300d0a557365722d4167656e743a20457870616e73652c20612050616c6f20416c746f204e6574776f726b7320636f6d70616e792c207365617263686573206163726f73732074686520676c6f62616c2049507634207370616365206d756c7469706c652074696d6573207065722064617920746f206964656e7469667920637573746f6d657273262333393b2070726573656e636573206f6e2074686520496e7465726e65742e20496620796f7520776f756c64206c696b6520746f206265206578636c756465642066726f6d206f7572207363616e732c20706c656173652073656e64204950206164647265737365732f646f6d61696e7320746f3a207363616e696e666f4070616c6f616c746f6e6574776f726b732e636f6d0d0a4163636570743a202a2f2a0d0a0d0a
[2022-04-25T08:39:38,223][ERROR][o.o.s.s.h.n.SecuritySSLNettyHttpServerTransport] [node-1] Exception during establishing a SSL connection: io.netty.handler.ssl.NotSslRecordException: not an SSL/TLS record: 474554202f5f616c696173657320485454502f312e310d0a486f73743a2035342e3137372e37362e37373a393230300d0a557365722d4167656e743a204d6f7a696c6c612f352e30207a677261622f302e780d0a4163636570743a202a2f2a0d0a4163636570742d456e636f64696e673a20677a69700d0a0d0a
[2022-04-25T08:48:16,762][ERROR][o.o.s.s.h.n.SecuritySSLNettyHttpServerTransport] [node-1] Exception during establishing a SSL connection: io.netty.handler.ssl.NotSslRecordException: not an SSL/TLS record: 474554202f5f73746174732f696e646963657320485454502f312e310d0a486f73743a2035342e3137372e37362e37373a393230300d0a557365722d4167656e743a204d6f7a696c6c612f352e30207a677261622f302e780d0a4163636570743a202a2f2a0d0a4163636570742d456e636f64696e673a20677a69700d0a0d0a
[2022-04-25T08:53:36,872][ERROR][o.o.s.s.h.n.SecuritySSLNettyHttpServerTransport] [node-1] Exception during establishing a SSL connection: io.netty.handler.ssl.NotSslRecordException: not an SSL/TLS record: 474554202f5f636c75737465722f6865616c74683f6c6576656c3d696e646963657320485454502f312e310d0a486f73743a2035342e3137372e37362e37373a393230300d0a557365722d4167656e743a204d6f7a696c6c612f352e30207a677261622f302e780d0a4163636570743a202a2f2a0d0a4163636570742d456e636f64696e673a20677a69700d0a0d0a
[2022-04-25T09:09:53,467][ERROR][o.o.s.s.h.n.SecuritySSLNettyHttpServerTransport] [node-1] Exception during establishing a SSL connection: io.netty.handler.ssl.NotSslRecordException: not an SSL/TLS record: 474554202f5f73746174757320485454502f312e310d0a486f73743a2035342e3137372e37362e37373a393230300d0a557365722d4167656e743a204d6f7a696c6c612f352e30207a677261622f302e780d0a4163636570743a202a2f2a0d0a4163636570742d456e636f64696e673a20677a69700d0a0d0a
[2022-04-25T10:24:06,383][ERROR][o.o.s.s.h.n.SecuritySSLNettyHttpServerTransport] [node-1] Exception during establishing a SSL connection: io.netty.handler.ssl.NotSslRecordException: not an SSL/TLS record: 474554202f20485454502f312e310d0a486f73743a2035342e3137372e37362e37370d0a0d0a

Some of the GET Requests written in hex in the previous log are:

GET /_aliases HTTP/1.1
Host: 54.177.76.77:9200
User-Agent: Mozilla/5.0 zgrab/0.x
Accept: */*
Accept-Encoding: gzip

GET / HTTP/1.0
User-Agent: Expanse, a Palo Alto Networks company, searches across the global IPv4 space multiple times per day to identify customers' presences on the Internet. If you would like to be excluded from our scans, please send IP addresses/domains to: scaninfo@paloaltonetworks.com
Accept: */*

GET /_cluster/health?level=indices HTTP/1.1
Host: 54.177.76.77:9200
User-Agent: Mozilla/5.0 zgrab/0.x
Accept: */*
Accept-Encoding: gzip

[verdx]

Update on Exception in thread "Attach Listener" investigation:

Based on a commentary in this stackoverflow thread, it seems the Attach Listener is a type of thread created by the JVM, by the Dynamic Attachment Mechanism. It talks about a JVM TI Agent, which can be the agent referenced in the error, Agent failed to start!. Furthermore, that logging is never used in Wazuh or Opensearch, which means the Agent is something internal.

The only reference to anything similar to this in the OpenSearch repositories is this. It is a Jenkins test where the expected output is:

"  Loaded: loaded (/usr/lib/systemd/system/opensearch.service; disabled; vendor preset: disabled)\n" +
                "   Active: active (running) since Mon 2022-04-04 21:41:23 UTC; 2h 52min ago\n" +
                "     Docs: https://opensearch.org/\n" +
                " Main PID: 32009 (java)\n" +
                "   CGroup: /system.slice/opensearch.service\n" +
                "           └─32009 /usr/share/opensearch/jdk/bin/java -Xshare:auto -Dopensearch.networkaddress.cache.ttl=60 -Dopensearch.networkaddress.cache.negative.ttl=1...\n" +
                "\n" +
                "Apr 04 21:41:25 dummy_desktop systemd-entrypoint[32009]: WARNING: An illegal reflective access operation has occurred\n" +
                "Apr 04 21:41:25 dummy_desktop systemd-entrypoint[32009]: WARNING: Illegal reflective access by org.opensearch.securi...name\n" +
                "Apr 04 21:41:25 dummy_desktop systemd-entrypoint[32009]: WARNING: Please consider reporting this to the maintainers ...tter\n" +
                "Apr 04 21:41:25 dummy_desktop systemd-entrypoint[32009]: WARNING: Use --illegal-access=warn to enable warnings of fu...ions\n" +
                "Apr 04 21:41:25 dummy_desktop systemd-entrypoint[32009]: WARNING: All illegal access operations will be denied in a ...ease\n" +
                "Apr 04 22:11:35 dummy_desktop systemd-entrypoint[32009]: Exception in thread \"Attach Listener\" Agent failed to start!\n" +
                "Apr 04 22:41:47 dummy_desktop systemd-entrypoint[32009]: Exception in thread \"Attach Listener\" Agent failed to start!\n" +
                "Apr 04 23:11:59 dummy_desktop systemd-entrypoint[32009]: Exception in thread \"Attach Listener\" Agent failed to start!\n" +
                "Apr 04 23:42:10 dummy_desktop systemd-entrypoint[32009]: Exception in thread \"Attach Listener\" Agent failed to start!\n" +
                "Apr 05 00:12:22 dummy_desktop systemd-entrypoint[32009]: Exception in thread \"Attach Listener\" Agent failed to start!\n" +
                "Hint: Some lines were ellipsized, use -l to show in full."

We can see the node is Active, which means at least in this build/run, this specific Exception is not a problem for the starting of the node.

This are the only other references to this exception I have found:
https://stackoverflow.com/questions/41399693/error-while-loadagent-in-java-virtualmachine
invesdwin/invesdwin-instrument#21

[verdx]

As seen in the last commentaries, this issue is closed as both the errors are external and do not interfere with the correct installation and behaviour of Wazuh.

• The first one is caused by automatic IP scanners that roam the internet, and the only problem is the open socket detects it is not SSL/TLS
• The second error also does not change the behaviour and it is considered acceptable by OpenSearch as seen in the presented test

[alberpilot]

Regarding the @verdx research, the found messages are justified so no deployment-product problem was found.