HttpEventCollector_Log4j2Test.java

/*
 * Copyright 2013-2014 Splunk, Inc.
 *
 * Licensed under the Apache License, Version 2.0 (the "License"): you may
 * not use this file except in compliance with the License. You may obtain
 * a copy of the License at
 *
 *     http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
 * WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
 * License for the specific language governing permissions and limitations
 * under the License.
 */

import com.google.gson.JsonObject;
import com.google.gson.JsonPrimitive;
import com.splunk.logging.HttpEventCollectorErrorHandler;
import com.splunk.logging.HttpEventCollectorEventInfo;
import org.apache.commons.lang3.StringUtils;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.core.LoggerContext;
import org.junit.Assert;
import org.junit.Test;

import java.util.ArrayList;
import java.util.Date;
import java.util.HashMap;
import java.util.List;

public final class HttpEventCollector_Log4j2Test {
    private String httpEventCollectorName = "Log4j2Test";
    final List<List<HttpEventCollectorEventInfo>> errors = new ArrayList<>();
    final List<Exception> logEx = new ArrayList<>();

    /**
     * sending a message via httplogging using log4j2 to splunk
     */
    @Test
    public void canSendEventUsingLog4j2() throws Exception {
        TestUtil.enableHttpEventCollector();
        String token = TestUtil.createHttpEventCollectorToken(httpEventCollectorName);
        String loggerName = "splunkLogger4j2";
        HashMap<String, String> userInputs = new HashMap<>();
        userInputs.put("user_logger_name", loggerName);
        userInputs.put("user_httpEventCollector_token", token);
        org.apache.logging.log4j.core.LoggerContext context = TestUtil.resetLog4j2Configuration("log4j2_template.xml", "log4j2.xml", userInputs);
        //use httplogger
        List<String> msgs = new ArrayList<>();

        Date date = new Date();
        String jsonMsg = String.format("{EventDate:%s, EventMsg:'this is a test event for log4j2}", date);

        Logger logger = context.getLogger(loggerName);
        logger.info(jsonMsg);
        msgs.add(jsonMsg);

        jsonMsg = String.format("{EventDate:%s, EventMsg:'this is a test error for log4j2}", date);
        logger.error(jsonMsg);
        msgs.add(jsonMsg);

        TestUtil.verifyEventsSentToSplunk(msgs);

        TestUtil.deleteHttpEventCollectorToken(httpEventCollectorName);
        System.out.println("====================== Test pass=========================");
    }

    /**
     * sending a message via httplogging using log4j2 to splunk
     */
    @Test
    public void canSendExceptionUsingLog4j2() throws Exception {
        TestUtil.enableHttpEventCollector();
        String token = TestUtil.createHttpEventCollectorToken(httpEventCollectorName);
        String loggerName = "splunkLogger4j2";
        HashMap<String, String> userInputs = new HashMap<>();
        userInputs.put("user_logger_name", loggerName);
        userInputs.put("user_httpEventCollector_token", token);
        org.apache.logging.log4j.core.LoggerContext context = TestUtil.resetLog4j2Configuration("log4j2_template.xml", "log4j2.xml", userInputs);
        //use httplogger
        List<String> msgs = new ArrayList<>();

        Date date = new Date();

        Logger logger = context.getLogger(loggerName);
        String jsonMsg = String.format("{EventDate:%s, EventMsg:'this is a test error for log4j2}", date);
        logger.error(jsonMsg, new RuntimeException("This is RuntimeException"));
        msgs.add(jsonMsg);

        TestUtil.verifyEventsSentToSplunk(msgs);

        TestUtil.deleteHttpEventCollectorToken(httpEventCollectorName);
        System.out.println("====================== Test pass=========================");
    }

    /**
     * Sending a message via httplogging using log4j2 to Splunk.
     *
     * @throws Exception
     */
    @Test
    public void canSendCommentedEventStringUsingLog4j2() throws Exception {
        TestUtil.enableHttpEventCollector();
        String token = TestUtil.createHttpEventCollectorToken(httpEventCollectorName);
        String loggerName = "splunkLogger4j2WithCommentedEventMessages";
        HashMap<String, String> userInputs = new HashMap<>();
        userInputs.put("user_logger_name", loggerName);
        userInputs.put("user_httpEventCollector_token", token);
        org.apache.logging.log4j.core.LoggerContext context = TestUtil.resetLog4j2Configuration("log4j2_template.xml", "log4j2.xml", userInputs);
        //use httplogger
        List<String> messages = new ArrayList<>();

        Date date = new Date();
        Logger logger = context.getLogger(loggerName);
        String commentedEventMessage = "// This is a single line commented string. Dated: " + date.toString();
        logger.info(commentedEventMessage);
        messages.add(commentedEventMessage);

        commentedEventMessage = "/* This is a document type commented string. */ Dated: " + date.toString();
        logger.error(commentedEventMessage);
        messages.add(commentedEventMessage);

        commentedEventMessage = "## This is a normal commented string. Dated: " + date.toString();
        logger.warn(commentedEventMessage);
        messages.add(commentedEventMessage);

        TestUtil.verifyEventsSentToSplunk(messages);

        TestUtil.deleteHttpEventCollectorToken(httpEventCollectorName);
        System.out.println("====================== Test pass=========================");
    }

    /**
     * sending a message via httplogging using log4j2 to splunk and set index, source and sourcetype
     */
    @Test
    public void canSendEventUsingLog4j2WithOptions() throws Exception {

        String token = TestUtil.createHttpEventCollectorToken(httpEventCollectorName);
        String loggerName = "splunkLogger4j2WithOptions";
        HashMap<String, String> userInputs = new HashMap<>();
        userInputs.put("user_logger_name", loggerName);
        userInputs.put("user_httpEventCollector_token", token);
        userInputs.put("user_index", "main");
        userInputs.put("user_host", "host.example.com");
        userInputs.put("user_source", "splunktest");
        userInputs.put("user_sourcetype", "battlecat");

        org.apache.logging.log4j.core.LoggerContext context = TestUtil.resetLog4j2Configuration("log4j2_template.xml", "log4j2.xml", userInputs);
        //use httplogger
        List<String> msgs = new ArrayList<>();

        Date date = new Date();
        String jsonMsg = String.format("{EventDate:%s, EventMsg:'this is a test event for log4j2}", date);

        Logger logger = context.getLogger(loggerName);
        logger.info(jsonMsg);
        msgs.add(jsonMsg);

        jsonMsg = String.format("{EventDate:%s, EventMsg:'this is a test error for log4j2}", date);
        logger.error(jsonMsg);
        msgs.add(jsonMsg);

        TestUtil.verifyEventsSentToSplunk(msgs);

        TestUtil.deleteHttpEventCollectorToken(httpEventCollectorName);
        System.out.println("====================== Test pass=========================");
    }

    /**
     * sending a message via httplogging using java.logging with batched_size_count
     */
    @Test
    public void sendBatchedEventsByCount() throws Exception {
        String token = TestUtil.createHttpEventCollectorToken(httpEventCollectorName);

        //clean out the events cache by setting send events immediately
        String loggerName = "splunkLoggerCountCleanCache";
        HashMap<String, String> userInputs = new HashMap<>();
        userInputs.put("user_logger_name", loggerName);
        userInputs.put("user_httpEventCollector_token", token);
        LoggerContext context = TestUtil.resetLog4j2Configuration("log4j2_template.xml", "log4j2.xml", userInputs);
        String jsonMsg = String.format("{EventDate:%s, EventMsg:'this is a test event for java logging}", new Date());
        Logger logger = context.getLogger(loggerName);
        logger.info(jsonMsg);

        loggerName = "splunkBatchLoggerCount";
        userInputs = new HashMap<>();
        userInputs.put("user_logger_name", loggerName);
        userInputs.put("user_httpEventCollector_token", token);
        userInputs.put("user_batch_interval","0");
        userInputs.put("user_batch_size_count", "5");
        userInputs.put("user_host", "host.example.com");
        userInputs.put("user_source", "splunktest_BatchCount");
        userInputs.put("user_sourcetype", "battlecat_BatchCount");

        context = TestUtil.resetLog4j2Configuration("log4j2_template.xml", "log4j2.xml", userInputs);
        logger = context.getLogger(loggerName);

        List<String> msgs = new ArrayList<>();

        jsonMsg = String.format("{EventDate:%s, EventMsg:'this is a test event for java logging1}", new Date());
        logger.info(jsonMsg);
        msgs.add(jsonMsg);
        System.out.println("event 1");
        TestUtil.verifyNoEventSentToSplunk(msgs);
        jsonMsg = String.format("{EventDate:%s, EventMsg:'this is a test event for java logging2}", new Date());
        logger.info(jsonMsg);
        msgs.add(jsonMsg);
        System.out.println("event 2");
        TestUtil.verifyNoEventSentToSplunk(msgs);
        jsonMsg = String.format("{EventDate:%s, EventMsg:'this is a test event for java logging3}", new Date());
        logger.info(jsonMsg);
        msgs.add(jsonMsg);
        System.out.println("event 3");
        TestUtil.verifyNoEventSentToSplunk(msgs);
        jsonMsg = String.format("{EventDate:%s, EventMsg:'this is a test event for java logging4}", new Date());
        logger.info(jsonMsg);
        msgs.add(jsonMsg);
        System.out.println("event 4");
        TestUtil.verifyNoEventSentToSplunk(msgs);

        Thread.sleep(6000);
        TestUtil.verifyNoEventSentToSplunk(msgs);

        jsonMsg = String.format("{EventDate:%s, EventMsg:'this is a test event for java logging5}", new Date());
        logger.info(jsonMsg);
        msgs.add(jsonMsg);

        TestUtil.verifyEventsSentToSplunk(msgs);

        TestUtil.deleteHttpEventCollectorToken(httpEventCollectorName);
    }

    /**
     * sending a message via httplogging using java.logging with batched_size_bytes
     */
    @Test
    public void sendBatchedEventsByBatchsize() throws Exception {
        String token = TestUtil.createHttpEventCollectorToken(httpEventCollectorName);
        String loggerName = "splunkLoggerBatchSize";
        HashMap<String, String> userInputs = new HashMap<>();
        userInputs.put("user_logger_name", loggerName);
        userInputs.put("user_httpEventCollector_token", token);
        userInputs.put("user_batch_size_bytes", "500");
        userInputs.put("user_batch_interval", "20000");
        userInputs.put("user_host", "host.example.com");
        userInputs.put("user_source", "splunktest_BatchSize");
        userInputs.put("user_sourcetype", "battlecat_BatchSize");

        LoggerContext context = TestUtil.resetLog4j2Configuration("log4j2_template.xml", "log4j2.xml", userInputs);
        Logger logger = context.getLogger(loggerName);

        List<String> msgs = new ArrayList<>();
        int size = 0;
        String jsonMsg = String.format("{EventDate:%s, EventMsg:'test event for log4j size 1}", new Date());
        logger.info(jsonMsg);
        size += jsonMsg.length();
        msgs.add(jsonMsg);
        jsonMsg = String.format("{EventDate:%s, EventMsg:'test event for log4j size 2}", new Date());
        size += jsonMsg.length();
        logger.info(jsonMsg);
        msgs.add(jsonMsg);

        Thread.sleep(6000);
        TestUtil.verifyNoEventSentToSplunk(msgs);

        jsonMsg = String.format("{EventDate:%s, EventMsg:'test event for log4j size 3, adding more msg to exceed the maxsize}", new Date());
        while (size + jsonMsg.length() < 550) {
            jsonMsg = String.format("%saaaaa", jsonMsg);
        }

        logger.info(jsonMsg);
        msgs.add(jsonMsg);

        TestUtil.verifyEventsSentToSplunk(msgs);
        TestUtil.deleteHttpEventCollectorToken(httpEventCollectorName);
    }

    /**
     * error handling
     */
    @Test
    public void errorHandlingInvalidToken() throws Exception {
        errors.clear();
        logEx.clear();
        //define error callback
        HttpEventCollectorErrorHandler.onError((data, ex) -> {
            synchronized (errors) {
                errors.add(data);
                logEx.add(ex);
            }
        });

        //create a token used for httpEventCollector logging, then make it becomes invalid
        httpEventCollectorName = "wrongtoken";
        String token = TestUtil.createHttpEventCollectorToken(httpEventCollectorName);
        String loggerName = "errorHandlingInvalidTokenLog4j";
        HashMap<String, String> userInputs = new HashMap<>();
        userInputs.put("user_logger_name", loggerName);
        userInputs.put("user_httpEventCollector_token", token);
        LoggerContext context = TestUtil.resetLog4j2Configuration("log4j2_template.xml", "log4j2.xml", userInputs);
        Logger logger = context.getLogger(loggerName);

        //disable the token so that it becomes invalid
        TestUtil.disableHttpEventCollector(httpEventCollectorName);
        Thread.sleep(5000);
        String jsonMsg = String.format("{EventDate:%s, EventMsg:'test event disabled token }", new Date());
        logger.info(jsonMsg);
        Thread.sleep(5000);

        //delete the token so that it becomes invalid
        TestUtil.deleteHttpEventCollectorToken(httpEventCollectorName);
        Thread.sleep(5000);
        jsonMsg = String.format("{EventDate:%s, EventMsg:'test event deleted token}", new Date());
        logger.info(jsonMsg);

        //wait for async process to return the error
        long startTime = System.currentTimeMillis();
        while (System.currentTimeMillis() - startTime < 60 * 1000)/*wait for up to 60s*/ {
            if (logEx.size() >= 2)
                break;
            Thread.sleep(1000);
        }

        for (List<HttpEventCollectorEventInfo> infos : errors) {
            for (HttpEventCollectorEventInfo info : infos) {
                System.out.println(info.getMessage());
            }
        }

        System.out.println("======print logEx");
        System.out.println(logEx);
        System.out.println("======finish print logEx");
        // in this case expect a valid http reply with a json error message
        HttpEventCollectorErrorHandler.ServerErrorException serverErrorException1 = (HttpEventCollectorErrorHandler.ServerErrorException) logEx.get(0);
        Assert.assertEquals("Token disabled", serverErrorException1.getErrorText());
        Assert.assertEquals(1, serverErrorException1.getErrorCode());
        HttpEventCollectorErrorHandler.ServerErrorException serverErrorException2 = (HttpEventCollectorErrorHandler.ServerErrorException) logEx.get(1);
        Assert.assertEquals("Invalid token", serverErrorException2.getErrorText());
        Assert.assertEquals(4, serverErrorException2.getErrorCode());


        Assert.assertEquals(2, errors.size());
    }


    /**
     * error handling
     */
    @Test
    public void errorHandlingDisabledHttpEventCollectorEndpoint() throws Exception {
        errors.clear();
        logEx.clear();

        //define error callback
        HttpEventCollectorErrorHandler.onError((data, ex) -> {
            synchronized (errors) {
                errors.add(data);
                logEx.add(ex);
            }
        });

        //create a token used for httpEventCollector logging, then make it becomes invalid
        httpEventCollectorName = "wrongtoken";
        String token = TestUtil.createHttpEventCollectorToken(httpEventCollectorName);
        String loggerName = "errorHandlingDisabledHttpEventCollectorEndpoint";
        HashMap<String, String> userInputs = new HashMap<>();
        userInputs.put("user_logger_name", loggerName);
        userInputs.put("user_httpEventCollector_token", token);
        LoggerContext context = TestUtil.resetLog4j2Configuration("log4j2_template.xml", "log4j2.xml", userInputs);
        Logger logger = context.getLogger(loggerName);


        //disable httpEventCollector endpoint
        TestUtil.disableHttpEventCollector();
        Thread.sleep(1000);
        String jsonMsg = String.format("{EventDate:%s, EventMsg:'test event httpEventCollector disabled}", new Date());
        logger.info(jsonMsg);

        //wait for async process to return the error
        long startTime = System.currentTimeMillis();
        while (System.currentTimeMillis() - startTime < 60 * 1000)/*wait for up to 60s*/ {
            if (logEx.size() >= 1)
                break;
            Thread.sleep(1000);
        }

        Assert.assertTrue(errors.size() >= 1);

        System.out.println(logEx);
        if (!StringUtils.containsAny(logEx.toString(), "Failed to connect to", "Remote host terminated the handshake", "Connection reset"))
            Assert.fail(String.format("Unexpected error message '%s'", logEx));
    }

    /**
     * verify events are index in correct order of the events were sent
     */
    @Test
    public void eventsIsIndexedInOrderOfSent() throws Exception {
        TestUtil.enableHttpEventCollector();

        String indexName="httpevents_in_order_l42";
        TestUtil.createIndex(indexName);
        String token = TestUtil.createHttpEventCollectorToken(httpEventCollectorName);
        String loggerName = "splunkLogger4j2OrderOfSent";
        HashMap<String, String> userInputs = new HashMap<>();
        userInputs.put("user_logger_name", loggerName);
        userInputs.put("user_httpEventCollector_token", token);
        userInputs.put("user_index", indexName);
        userInputs.put("user_send_mode", "sequential");

        org.apache.logging.log4j.core.LoggerContext context = TestUtil.resetLog4j2Configuration("log4j2_template.xml", "log4j2.xml", userInputs);

        //send multiple events and verify they are indexed in the order of sending
        List<String> msgs = new ArrayList<>();
        int totalEventsCount = 1000;
        Logger logger = context.getLogger(loggerName);
        String prefix="log4j2 multiple events";
        for (int i = 0; i < totalEventsCount; i++) {
            String jsonMsg = String.format("%s %s", prefix,i);
            logger.info(jsonMsg);
            msgs.add(jsonMsg);
        }

        TestUtil.verifyEventsSentInOrder(prefix,totalEventsCount,indexName);

        TestUtil.deleteHttpEventCollectorToken(httpEventCollectorName);
        System.out.println("====================== Test pass=========================");
    }
    
    /**
     * Test sending a JSON and text message with "_json" source type via http logging appender using log4j 2.x logger
     */
    @Test
    public void canSendJsonEventUsingUtilLoggerWithJsonSourceType() throws Exception {
        canSendJsonEventUsingUtilLoggerWithSourceType("_json");
    }
    
    /**
     * Test sending a JSON and text message with "battlecat_test" source type via http logging appender using log4j 2.x logger
     */
    @Test
    public void canSendJsonEventUsingUtilLoggerWithDefaultSourceType() throws Exception {
        canSendJsonEventUsingUtilLoggerWithSourceType("battlecat_test");
    }

    private void canSendJsonEventUsingUtilLoggerWithSourceType(final String sourceType) throws Exception {
        final String token = TestUtil.createHttpEventCollectorToken(httpEventCollectorName);

        final String loggerName = "splunkLog4j2";
        
        // Build User input map
        final HashMap<String, String> userInputs = TestUtil.buildUserInputMap(loggerName, token, sourceType, "json");
        
        final LoggerContext context = TestUtil.resetLog4j2Configuration("log4j2_template.xml", "log4j2.xml", userInputs);
        
        final Logger logger = context.getLogger(loggerName);

        final List<String> msgs = new ArrayList<>();

        final long timeMillsec = new Date().getTime();

        final JsonObject jsonObject = new JsonObject();
        jsonObject.add("transactionId", new JsonPrimitive("11"));
        jsonObject.add("userId", new JsonPrimitive("21"));
        jsonObject.add("eventTimestamp", new JsonPrimitive(timeMillsec));

        // Test with a json event message
        jsonObject.add("severity", new JsonPrimitive("info"));
        final String infoJson = jsonObject.toString();
        logger.info(infoJson);
        msgs.add(infoJson);


        // Test with a text event message
        final String infoText = String.format("{EventTimestamp:%s, EventMsg:'this is a text info for log4j2 logger}", timeMillsec);
        logger.info(infoText);
        msgs.add(infoText);

        TestUtil.verifyEventsSentToSplunk(msgs);
        TestUtil.deleteHttpEventCollectorToken(httpEventCollectorName);
    }
}