[BUG] Triple logging of audit messages

[jchipmunk]

What is the bug?
OpenSearch log contains extra audit messages:

[2022-08-05T08:03:52,622][INFO ][sgaudit                  ] [opensearch-1] {"audit_cluster_name":"opensearch","audit_transport_headers":{"_system_index_access_allowed":"false"},"audit_node_name":"opensearch-1","audit_trace_task_id":"wlV1pg8FSlWuVvCZgniL8w:104","audit_transport_request_type":"GetIndexRequest","audit_category":"INDEX_EVENT","audit_request_origin":"REST","audit_node_id":"wlV1pg8FSlWuVvCZgniL8w","audit_request_layer":"TRANSPORT","@timestamp":"2022-08-05T08:03:52.595+00:00","audit_format_version":4,"audit_request_remote_address":"192.168.160.1","audit_request_privilege":"indices:admin/get","audit_node_host_address":"192.168.160.2","audit_request_effective_user":"admin","audit_trace_indices":[".opendistro_security"],"audit_trace_resolved_indices":[".opendistro_security"],"audit_node_host_name":"192.168.160.2"}
[2022-08-05T08:03:52,623][WARN ][sgaudit                  ] [opensearch-1] {"audit_cluster_name":"opensearch","audit_transport_headers":{"_system_index_access_allowed":"false"},"audit_node_name":"opensearch-1","audit_trace_task_id":"wlV1pg8FSlWuVvCZgniL8w:104","audit_transport_request_type":"GetIndexRequest","audit_category":"INDEX_EVENT","audit_request_origin":"REST","audit_node_id":"wlV1pg8FSlWuVvCZgniL8w","audit_request_layer":"TRANSPORT","@timestamp":"2022-08-05T08:03:52.595+00:00","audit_format_version":4,"audit_request_remote_address":"192.168.160.1","audit_request_privilege":"indices:admin/get","audit_node_host_address":"192.168.160.2","audit_request_effective_user":"admin","audit_trace_indices":[".opendistro_security"],"audit_trace_resolved_indices":[".opendistro_security"],"audit_node_host_name":"192.168.160.2"}
[2022-08-05T08:03:52,623][ERROR][sgaudit                  ] [opensearch-1] {"audit_cluster_name":"opensearch","audit_transport_headers":{"_system_index_access_allowed":"false"},"audit_node_name":"opensearch-1","audit_trace_task_id":"wlV1pg8FSlWuVvCZgniL8w:104","audit_transport_request_type":"GetIndexRequest","audit_category":"INDEX_EVENT","audit_request_origin":"REST","audit_node_id":"wlV1pg8FSlWuVvCZgniL8w","audit_request_layer":"TRANSPORT","@timestamp":"2022-08-05T08:03:52.595+00:00","audit_format_version":4,"audit_request_remote_address":"192.168.160.1","audit_request_privilege":"indices:admin/get","audit_node_host_address":"192.168.160.2","audit_request_effective_user":"admin","audit_trace_indices":[".opendistro_security"],"audit_trace_resolved_indices":[".opendistro_security"],"audit_node_host_name":"192.168.160.2"}

How can one reproduce the bug?
Steps to reproduce the behavior:

1. Perform the following request:

   curl -XGET http://localhost:19200/.opendistro_security
   

   to get information about .opendistro_security index.
2. Check log messages

What is the expected behavior?
The log must only contain one audit message instead of three:

[2022-08-05T08:03:52,622][INFO ][sgaudit                  ] [opensearch-1] {"audit_cluster_name":"opensearch","audit_transport_headers":{"_system_index_access_allowed":"false"},"audit_node_name":"opensearch-1","audit_trace_task_id":"wlV1pg8FSlWuVvCZgniL8w:104","audit_transport_request_type":"GetIndexRequest","audit_category":"INDEX_EVENT","audit_request_origin":"REST","audit_node_id":"wlV1pg8FSlWuVvCZgniL8w","audit_request_layer":"TRANSPORT","@timestamp":"2022-08-05T08:03:52.595+00:00","audit_format_version":4,"audit_request_remote_address":"192.168.160.1","audit_request_privilege":"indices:admin/get","audit_node_host_address":"192.168.160.2","audit_request_effective_user":"admin","audit_trace_indices":[".opendistro_security"],"audit_trace_resolved_indices":[".opendistro_security"],"audit_node_host_name":"192.168.160.2"}

What is your host/environment?

• OS: Linux
• Version: 1.3.4
• Plugins: OpenSearch Security

Do you have any screenshots?
n/a

Do you have any additional context?
The bug is the incorrect usage of switch-case construction in org.opensearch.security.auditlog.sink.Log4JSink class:

private boolean isLogLevelEnabled(Logger logger, Level level) {
    boolean isEnabled = false;
    switch(level.toString()) {
        case "TRACE": isEnabled = logger.isTraceEnabled();
        case "DEBUG": isEnabled = logger.isDebugEnabled();
        case "INFO": isEnabled = logger.isInfoEnabled();
        case "WARN": isEnabled = logger.isWarnEnabled();
        case "ERROR": isEnabled = logger.isErrorEnabled();
    }
    return isEnabled;
}

private void logAtLevel(Logger logger, Level level, String msg) {
    switch(level.toString()) {
        case "TRACE": logger.trace(msg);
        case "DEBUG": logger.debug(msg);
        case "INFO": logger.info(msg);
        case "WARN": logger.warn(msg);
        case "ERROR": logger.error(msg);
    }
}

This code does not contain break/return keywords to stop switching.
It seems the changes were not rolled back in PR: Switch to log4j logger.

[peternied]

Thanks for filing, and thank you for the pull request!