ch.qos.logback.classic.spi.LoggingEvent Java Examples

@Test
public void testAppenderMultipleEvent() {
	Marker multi = SecurityMarkers.getMarker(
			SecurityMarkers.SECURITY_AUDIT, SecurityMarkers.CONFIDENTIAL);
	LOGGER.info(multi,
			"This statement contains multiple markers: audit and confidential");

	// Now verify our logging interactions
	verify(mockAppender).doAppend(captorLoggingEvent.capture());

	// Get the logging event from the captor
	LoggingEvent loggingEvent = captorLoggingEvent.getValue();
	System.out.println("testAppender(): loggingEvent: " + loggingEvent);

	// check the filter chain decision for this event
	assertEquals(FilterReply.DENY,
			mockAppender.getFilterChainDecision(loggingEvent));
}
 

@Test
public void testAppenderSecuritySuccess() {
	LOGGER.info(SecurityMarkers.SECURITY_SUCCESS,
			"This statement is a security success");

	// Now verify our logging interactions
	verify(mockAppender).doAppend(captorLoggingEvent.capture());

	// Get the logging event from the captor
	LoggingEvent loggingEvent = captorLoggingEvent.getValue();
	System.out.println("testAppender(): loggingEvent: " + loggingEvent);

	// check the filter chain decision for this event
	assertEquals(FilterReply.ACCEPT,
			mockAppender.getFilterChainDecision(loggingEvent));
}
 

@Test
public void testAppenderMultipleNonSecurityEvent() {
	Marker multi = SecurityMarkers.getMarker(SecurityMarkers.EVENT_SUCCESS,
			SecurityMarkers.CONFIDENTIAL);
	System.out.println("MARKER: " + multi);
	LOGGER.info(multi,
			"This statement contains multiple markers: event success and confidential");

	// Now verify our logging interactions
	verify(mockAppender).doAppend(captorLoggingEvent.capture());

	// Get the logging event from the captor
	LoggingEvent loggingEvent = captorLoggingEvent.getValue();
	System.out.println("testAppender(): loggingEvent: " + loggingEvent);

	// check the filter chain decision for this event
	assertEquals(FilterReply.DENY,
			mockAppender.getFilterChainDecision(loggingEvent));
}
 

@Test
public void testAppenderMultipleEvent() {
	Marker multi = SecurityMarkers.getMarker(
			SecurityMarkers.SECURITY_AUDIT, SecurityMarkers.CONFIDENTIAL);
	LOGGER.info(multi,
			"This statement contains multiple markers: security audit and confidential");

	// Now verify our logging interactions
	verify(mockAppender).doAppend(captorLoggingEvent.capture());

	// Get the logging event from the captor
	LoggingEvent loggingEvent = captorLoggingEvent.getValue();
	System.out.println("testAppender(): loggingEvent: " + loggingEvent);

	// check the filter chain decision for this event
	assertEquals(FilterReply.ACCEPT,
			mockAppender.getFilterChainDecision(loggingEvent));
}
 

/**
 * Test that masking works for combinations of markers and not just
 * SecurityMarkers.CONFIDENTIAL
 *
 * @see https://github.com/javabeanz/owasp-security-logging/issues/19
 */
@Test
public void markerTest() {
    Marker multiMarker = SecurityMarkers.getMarker(SecurityMarkers.CONFIDENTIAL, SecurityMarkers.SECURITY_FAILURE);

    String ssn = "123-45-6789";
    LOGGER.info(multiMarker, "ssn={}", ssn);

    // Now verify our logging interactions
    verify(mockAppender).doAppend(captorLoggingEvent.capture());

    // Get the logging event from the captor
    final LoggingEvent loggingEvent = captorLoggingEvent.getValue();

    // Check the message being logged is correct
    String layoutMessage = encoder.getLayout().doLayout(loggingEvent);
    assertTrue(layoutMessage.contains("ssn=" + MaskingConverter.MASKED_PASSWORD));
}
 

@Test
public void shouldLogContextPropertyHostname() {
  LoggerContext context = new LoggerContext();
  context.putProperty("hostname", HOSTNAME);

  MillisecondPrecisionSyslogStartConverter millisecondPrecisionSyslogStartConverter =
      new MillisecondPrecisionSyslogStartConverter();
  millisecondPrecisionSyslogStartConverter.setContext(context);
  millisecondPrecisionSyslogStartConverter.setOptionList(ImmutableList.of("LOCAL0"));
  millisecondPrecisionSyslogStartConverter.start();

  LoggingEvent event = new LoggingEvent();
  event.setLevel(Level.INFO);
  String message = millisecondPrecisionSyslogStartConverter.convert(event);

  assertTrue(message.contains(HOSTNAME));
}
 

@Test
public void customLevelNameKey() throws IOException {
    encoder.setIncludeLevelName(true);
    encoder.setLevelNameKey("Severity");
    encoder.start();

    final LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
    final Logger logger = lc.getLogger(LOGGER_NAME);

    final LoggingEvent event = simpleLoggingEvent(logger, null);

    final String logMsg = encodeToStr(event);

    final ObjectMapper om = new ObjectMapper();
    final JsonNode jsonNode = om.readTree(logMsg);
    basicValidation(jsonNode);
    assertEquals("DEBUG", jsonNode.get("_Severity").textValue());
    assertNull(jsonNode.get("_exception"));
}
 

@Test
public void customLoggerNameKey() throws IOException {
    encoder.setLoggerNameKey("Logger");
    encoder.start();

    final LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
    final Logger logger = lc.getLogger(LOGGER_NAME);

    final LoggingEvent event = simpleLoggingEvent(logger, null);

    final String logMsg = encodeToStr(event);

    final ObjectMapper om = new ObjectMapper();
    final JsonNode jsonNode = om.readTree(logMsg);
    coreValidation(jsonNode);
    assertNotNull(jsonNode.get("_thread_name").textValue());
    assertEquals(LOGGER_NAME, jsonNode.get("_Logger").textValue());
    assertNull(jsonNode.get("_exception"));
}
 

@Test
public void givenNettyHttpClientWithCustomLogger_whenEndpointIsConsumed_thenRequestAndResponseBodyLogged() {

    reactor.netty.http.client.HttpClient httpClient = HttpClient
      .create()
      .tcpConfiguration(
        tc -> tc.bootstrap(
          b -> BootstrapHandlers.updateLogSupport(b, new CustomLogger(HttpClient.class))));
    WebClient
      .builder()
      .clientConnector(new ReactorClientHttpConnector(httpClient))
      .build()
      .post()
      .uri(sampleUrl)
      .body(BodyInserters.fromObject(post))
      .exchange()
      .block();

    verify(nettyAppender).doAppend(argThat(argument -> (((LoggingEvent) argument).getFormattedMessage()).contains(sampleResponseBody)));
}
 

@Test
public void customThreadNameKey() throws IOException {
    encoder.setThreadNameKey("Thread");
    encoder.start();

    final LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
    final Logger logger = lc.getLogger(LOGGER_NAME);

    final LoggingEvent event = simpleLoggingEvent(logger, null);

    final String logMsg = encodeToStr(event);

    final ObjectMapper om = new ObjectMapper();
    final JsonNode jsonNode = om.readTree(logMsg);
    coreValidation(jsonNode);
    assertNotNull(jsonNode.get("_Thread").textValue());
    assertEquals(LOGGER_NAME, jsonNode.get("_logger_name").textValue());
    assertNull(jsonNode.get("_exception"));
}
 

@Test
public void numericValueAsNumber() throws IOException {
    encoder.start();

    final LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
    final Logger logger = lc.getLogger(LOGGER_NAME);

    final LoggingEvent event = simpleLoggingEvent(logger, null);

    event.setMDCPropertyMap(ImmutableMap.of("int", "200", "float", "0.00001"));

    final String logMsg = encodeToStr(event);

    final ObjectMapper om = new ObjectMapper();
    final JsonNode jsonNode = om.readTree(logMsg);
    basicValidation(jsonNode);

    assertTrue(logMsg.contains("\"_int\":200"));
    assertTrue(logMsg.contains("\"_float\":0.00001"));
}
 

@Test
public void shouldNotCaptureTenantAwareLogWhenEventHasNoContextLogLevel(){
    ILoggingEvent logEvent = new LoggingEvent(
            LOG.getName(),
            LOG,
            Level.DEBUG,
            "Test Message",
            null,
            new Object[]{device.toURI()}
    );

    konkerLoggerAppender.append(logEvent);
    Mockito.verify(konkerLoggerAppender, Mockito.never())
            .store(Mockito.any(),
                    Mockito.anyString(),
                    Mockito.anyString(),
                    Mockito.anyString());
}
 

@Test
public void givenNettyHttpClientWithWiretap_whenEndpointIsConsumed_thenRequestAndResponseBodyLogged() {

    reactor.netty.http.client.HttpClient httpClient = HttpClient
      .create()
      .wiretap(true);
    WebClient
      .builder()
      .clientConnector(new ReactorClientHttpConnector(httpClient))
      .build()
      .post()
      .uri(sampleUrl)
      .body(BodyInserters.fromObject(post))
      .exchange()
      .block();

    verify(nettyAppender).doAppend(argThat(argument -> (((LoggingEvent) argument).getFormattedMessage()).contains("00000300")));
}
 

@Test
public void testAppenderSecurityAudit() {
	LOGGER.info(SecurityMarkers.SECURITY_AUDIT,
			"This statement is a security audit");

	// Now verify our logging interactions
	verify(mockAppender).doAppend(captorLoggingEvent.capture());

	// Get the logging event from the captor
	LoggingEvent loggingEvent = captorLoggingEvent.getValue();
	System.out.println("testAppender(): loggingEvent: " + loggingEvent);

	// check the filter chain decision for this event
	assertEquals(FilterReply.ACCEPT,
			mockAppender.getFilterChainDecision(loggingEvent));
}
 

@Test
public void multipleMarker() throws IOException {
    encoder.setLoggerNameKey("Logger");
    encoder.start();

    final LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
    final Logger logger = lc.getLogger(LOGGER_NAME);

    final LoggingEvent event = simpleLoggingEvent(logger, null);
    final Marker marker = MarkerFactory.getMarker("FIRST");
    marker.add(MarkerFactory.getMarker("SECOND"));
    event.setMarker(marker);

    final String logMsg = encodeToStr(event);

    final ObjectMapper om = new ObjectMapper();
    final JsonNode jsonNode = om.readTree(logMsg);
    coreValidation(jsonNode);
    assertEquals("FIRST, SECOND", jsonNode.get("_marker").textValue());
}
 

@Test
public void givenJettyHttpClient_whenEndpointIsConsumed_thenRequestAndResponseBodyLogged() {
    SslContextFactory.Client sslContextFactory = new SslContextFactory.Client();
    org.eclipse.jetty.client.HttpClient httpClient = new org.eclipse.jetty.client.HttpClient(sslContextFactory) {
        @Override
        public Request newRequest(URI uri) {
            Request request = super.newRequest(uri);
            return enhance(request);
        }
    };

    WebClient
      .builder()
      .clientConnector(new JettyClientHttpConnector(httpClient))
      .build()
      .post()
      .uri(sampleUrl)
      .body(BodyInserters.fromObject(post))
      .retrieve()
      .bodyToMono(String.class)
      .block();

    verify(jettyAppender).doAppend(argThat(argument -> (((LoggingEvent) argument).getFormattedMessage()).contains(sampleResponseBody)));
}
 

@Test
public void test() {
	String userid = "myId";
	String password = "secret";
	LOGGER.info(SecurityMarkers.CONFIDENTIAL, "userid={}, password='{}'",
			userid, password);

	// Now verify our logging interactions
	verify(mockAppender).doAppend(captorLoggingEvent.capture());

	// Get the logging event from the captor
	final LoggingEvent loggingEvent = captorLoggingEvent.getValue();

	// Check log level is correct
	assertThat(loggingEvent.getLevel(), is(Level.INFO));

	// Check the message being logged is correct
	String layoutMessage = encoder.getLayout().doLayout(loggingEvent);
	assertTrue(layoutMessage.contains("userid="
			+ MaskingConverter.MASKED_PASSWORD + ", password='"
			+ MaskingConverter.MASKED_PASSWORD + "'"));
	assertFalse(layoutMessage.contains("secret"));
}
 

@Test
public void shouldLogRestClientStartEventWithRequestId() {

    String requestId = UUID.randomUUID().toString();
    URI requestUrl = URI.create("/publicapi-request");
    String requestMethod = "GET";
    MultivaluedMap<String, Object> mockHeaders = new MultivaluedHashMap<>();

    when(clientRequestContext.getUri()).thenReturn(requestUrl);
    when(clientRequestContext.getMethod()).thenReturn(requestMethod);
    when(clientRequestContext.getHeaders()).thenReturn(mockHeaders);
    MDC.put(LoggingKeys.MDC_REQUEST_ID_KEY, requestId);

    loggingFilter.filter(clientRequestContext);

    verify(mockAppender, times(1)).doAppend(loggingEventArgumentCaptor.capture());
    List<LoggingEvent> loggingEvents = loggingEventArgumentCaptor.getAllValues();

    assertThat(loggingEvents.get(0).getFormattedMessage(), is(format("[%s] - %s to %s began", requestId, requestMethod, requestUrl)));

}
 

@Override
public FilterReply decide(E eventObject) {
    if (!isStarted()) {
        return FilterReply.NEUTRAL;
    }

    LoggingEvent event = (LoggingEvent) eventObject;

    if (this.levelMin != null && !event.getLevel().isGreaterOrEqual(levelMin)) {
        return DENY;
    }

    if (this.levelMax != null && event.getLevel().toInt() > levelMax.toInt()) {
        return DENY;
    }

    if (acceptOnMatch) {
        return ACCEPT;
    } else {
        return NEUTRAL;
    }
}
 

public static LoggingEvent simpleLoggingEvent(final Logger logger, final Throwable e) {
    return new LoggingEvent(
        LOGGER_NAME,
        logger,
        Level.DEBUG,
        "message {}",
        e,
        new Object[]{1});
}
 

@Test
public void testAppenderNormalEvent() {
	LOGGER.info("This statement is NOT confidential");

	// Now verify our logging interactions
	verify(mockAppender).doAppend(captorLoggingEvent.capture());

	// Get the logging event from the captor
	LoggingEvent loggingEvent = captorLoggingEvent.getValue();
	System.out.println("testAppender(): loggingEvent: " + loggingEvent);

	// check the filter chain decision for this event
	assertEquals(FilterReply.NEUTRAL,
			mockAppender.getFilterChainDecision(loggingEvent));
}
 

@Test
public void shouldLogRestClientEndEventWithRequestIdAndElapsedTime() {

    String requestId = UUID.randomUUID().toString();
    URI requestUrl = URI.create("/publicapi-request");
    String requestMethod = "GET";

    when(clientRequestContext.getUri()).thenReturn(requestUrl);
    when(clientRequestContext.getMethod()).thenReturn(requestMethod);
    MultivaluedMap<String, Object> mockHeaders = new MultivaluedHashMap<>();
    MultivaluedMap<String, String> mockHeaders2 = new MultivaluedHashMap<>();

    when(clientRequestContext.getHeaders()).thenReturn(mockHeaders);
    when(clientResponseContext.getHeaders()).thenReturn(mockHeaders2);
    MDC.put(LoggingKeys.MDC_REQUEST_ID_KEY, requestId);
    loggingFilter.filter(clientRequestContext);

    loggingFilter.filter(clientRequestContext, clientResponseContext);

    verify(mockAppender, times(2)).doAppend(loggingEventArgumentCaptor.capture());
    List<LoggingEvent> loggingEvents = loggingEventArgumentCaptor.getAllValues();

    assertThat(loggingEvents.get(0).getFormattedMessage(), is(format("[%s] - %s to %s began", requestId, requestMethod, requestUrl)));
    String endLogMessage = loggingEvents.get(1).getFormattedMessage();
    assertThat(endLogMessage, containsString(format("[%s] - %s to %s ended - total time ", requestId, requestMethod, requestUrl)));
    String[] timeTaken = StringUtils.substringsBetween(endLogMessage, "total time ", "ms");
    assertTrue(NumberUtils.isCreatable(timeTaken[0]));

}
 

@Test
public void shouldPartitionByEventThreadName() {
    ctx.setName(LOGGER_CONTEXT_NAME);
    unit.setContext(ctx);
    final ILoggingEvent evt = new LoggingEvent("fqcn", ctx.getLogger("logger"), Level.ALL, "msg", null, new Object[0]);
    Assert.assertThat(unit.createKey(evt), Matchers.equalTo(ByteBuffer.allocate(4).putInt(LOGGER_CONTEXT_NAME.hashCode()).array()));
}
 

@Test
public void should_satisfy_convert_with_masked_string() {
    ILoggingEvent iLoggingEvent = new LoggingEvent();
    ((LoggingEvent) iLoggingEvent).setMessage(getXML());
    String formatted = new LUHNMaskingConverter().convert(iLoggingEvent);
    assertThat(formatted).isNotNull().isXmlEqualTo(expectedXml());
}
 

@Test
public void shouldPublishEventWithJobIdAndLevelWARN() {
    // given
    final LoggingEvent loggingEvent = createLoggingEvent(Level.WARN);

    // when
    jobEventAppender.append(loggingEvent);

    // then
    final ArgumentCaptor<JobMessage> messageCaptor = forClass(JobMessage.class);
    verify(jobService).appendMessage(eq("someJobId"), messageCaptor.capture());

    assertMessageEvent(messageCaptor, de.otto.edison.jobs.domain.Level.WARNING);
}
 

@Test
public void verifyNoFilteringPassesAllEvents() {
  final List<Level> allLevels = asList(OFF, ERROR, WARN, INFO, DEBUG, TRACE, ALL);
  final LevelRangeFilter filter = new LevelRangeFilter();
  filter.start();

  for (final Level level : allLevels) {
    final LoggingEvent event = new LoggingEvent();
    event.setLevel(level);
    assertEquals(FilterReply.NEUTRAL, filter.decide(event));
  }
}
 

@Test
public void testDecideILoggingEvent() {
	LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();

	// create a new marker filter
	MarkerFilter mkt = new MarkerFilter();
	mkt.setContext(lc);
	mkt.setMarker(SecurityMarkers.CONFIDENTIAL_MARKER_NAME);
	mkt.setOnMatch(FilterReply.ACCEPT);
	mkt.setOnMismatch(FilterReply.DENY);
	mkt.start();
	assertTrue(mkt.isStarted());

	// test a logging event with no markers
	ILoggingEvent nulEvent = new LoggingEvent();
	assertEquals(FilterReply.DENY, mkt.decide(nulEvent));

	// test a logging event with the CONFIDENTIAL marker
	LoggingEvent confidentialEvent = new LoggingEvent();
	confidentialEvent.setMarker(SecurityMarkers.CONFIDENTIAL);
	assertEquals(FilterReply.ACCEPT, mkt.decide(confidentialEvent));

	// test a logging event without the CONFIDENTIAL marker
	LoggingEvent normalEvent = new LoggingEvent();
	normalEvent.setMarker(SecurityMarkers.EVENT_SUCCESS);
	assertEquals(FilterReply.DENY, mkt.decide(nulEvent));

	Logger LOGGER = lc.getLogger(MarkerFilterTest.class);
	LOGGER.debug(SecurityMarkers.TOP_SECRET, "You should not see this!");
	LOGGER.debug(SecurityMarkers.CONFIDENTIAL,
			"Look at this confidential information!");
}
 

@Test
public void testAppendUsesKeying() {
    when(encoder.encode(any(ILoggingEvent.class))).thenReturn(new byte[]{0x00, 0x00});
    unit.start();
    final LoggingEvent evt = new LoggingEvent("fqcn",ctx.getLogger("logger"), Level.ALL, "message", null, new Object[0]);
    unit.append(evt);
    verify(deliveryStrategy).send(any(KafkaProducer.class), any(ProducerRecord.class), eq(evt), any(FailedDeliveryCallback.class));
    verify(keyingStrategy).createKey(same(evt));
    verify(deliveryStrategy).send(any(KafkaProducer.class), any(ProducerRecord.class), eq(evt), any(FailedDeliveryCallback.class));
}
 

@Test
public void testAppendUsesPreConfiguredPartition() {
    when(encoder.encode(any(ILoggingEvent.class))).thenReturn(new byte[]{0x00, 0x00});
    ArgumentCaptor<ProducerRecord> producerRecordCaptor = ArgumentCaptor.forClass(ProducerRecord.class);
    unit.setPartition(1);
    unit.start();
    final LoggingEvent evt = new LoggingEvent("fqcn", ctx.getLogger("logger"), Level.ALL, "message", null, new Object[0]);
    unit.append(evt);
    verify(deliveryStrategy).send(any(KafkaProducer.class), producerRecordCaptor.capture(), eq(evt), any(FailedDeliveryCallback.class));
    final ProducerRecord value = producerRecordCaptor.getValue();
    assertThat(value.partition(), equalTo(1));
}
 

@Test
public void injectionTest() {

	LOGGER.info("This message contains \r\n line feeds");

	// Now verify our logging interactions
	verify(mockAppender).doAppend(captorLoggingEvent.capture());

	// Get the logging event from the captor
	final LoggingEvent loggingEvent = captorLoggingEvent.getValue();

	System.out.println("MESSAGE: " + loggingEvent.getFormattedMessage());
	// assertThat(loggingEvent.getFormattedMessage(),
	// is("This message contains line feeds"));
}