gerrit.onap Code Review - sdc.git/blob

   1 /*
   2  * Copyright © 2016-2018 European Support Limited
   3  *
   4  * Licensed under the Apache License, Version 2.0 (the "License");
   5  * you may not use this file except in compliance with the License.
   6  * You may obtain a copy of the License at
   7  *
   8  *      http://www.apache.org/licenses/LICENSE-2.0
   9  *
  10  * Unless required by applicable law or agreed to in writing, software
  11  * distributed under the License is distributed on an "AS IS" BASIS,
  12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  13  * See the License for the specific language governing permissions and
  14  * limitations under the License.
  15  */
  16
  17 package org.openecomp.sdc.logging.slf4j;
  18
  19 import static org.openecomp.sdc.logging.slf4j.SLF4JLoggerWrapper.BEGIN_TIMESTAMP;
  20 import static org.openecomp.sdc.logging.slf4j.SLF4JLoggerWrapper.CLIENT_IP_ADDRESS;
  21 import static org.openecomp.sdc.logging.slf4j.SLF4JLoggerWrapper.ELAPSED_TIME;
  22 import static org.openecomp.sdc.logging.slf4j.SLF4JLoggerWrapper.END_TIMESTAMP;
  23 import static org.openecomp.sdc.logging.slf4j.SLF4JLoggerWrapper.RESPONSE_CODE;
  24 import static org.openecomp.sdc.logging.slf4j.SLF4JLoggerWrapper.RESPONSE_DESCRIPTION;
  25 import static org.openecomp.sdc.logging.slf4j.SLF4JLoggerWrapper.STATUS_CODE;
  26 import static org.testng.Assert.assertEquals;
  27 import static org.testng.Assert.assertNotNull;
  28 import static org.testng.Assert.assertNull;
  29
  30 import java.lang.reflect.InvocationHandler;
  31 import java.lang.reflect.Method;
  32 import java.lang.reflect.Proxy;
  33 import java.util.Arrays;
  34 import java.util.Map;
  35 import org.openecomp.sdc.logging.api.AuditData;
  36 import org.openecomp.sdc.logging.api.StatusCode;
  37 import org.slf4j.Logger;
  38 import org.slf4j.MDC;
  39 import org.testng.annotations.Test;
  40
  41 /**
  42  * @author EVITALIY
  43  * @since 05 Mar 18
  44  */
  45 public class SLF4JLoggerWrapperTest {
  46
  47     @Test
  48     public void auditDoesNotFailWhenInputNull() {
  49         new SLF4JLoggerWrapper(this.getClass()).audit(null);
  50     }
  51
  52     @Test
  53     public void beginTimeAvailableWhenPassed() {
  54         SpyLogger spy = createSpy();
  55         long start = System.currentTimeMillis();
  56         new SLF4JLoggerWrapper(spy).audit(AuditData.builder().startTime(start).build());
  57         assertNotNull(spy.mdc().get(BEGIN_TIMESTAMP));
  58     }
  59
  60     @Test
  61     public void entTimeAvailableWhenPassed() {
  62         SpyLogger spy = createSpy();
  63         long end = System.currentTimeMillis();
  64         new SLF4JLoggerWrapper(spy).audit(AuditData.builder().endTime(end).build());
  65         assertNotNull(spy.mdc().get(END_TIMESTAMP));
  66     }
  67
  68     @Test
  69     public void elapsedTimeAvailableWhenPassed() {
  70         SpyLogger spy = createSpy();
  71         long start = System.currentTimeMillis();
  72         new SLF4JLoggerWrapper(spy).audit(AuditData.builder()
  73             .startTime(start).endTime(start).build());
  74         assertNotNull(spy.mdc().get(ELAPSED_TIME));
  75     }
  76
  77     @Test
  78     public void statusCodeAvailableWhenPassed() {
  79         SpyLogger spy = createSpy();
  80         new SLF4JLoggerWrapper(spy).audit(AuditData.builder().statusCode(StatusCode.COMPLETE).build());
  81         assertEquals(spy.mdc().get(STATUS_CODE), StatusCode.COMPLETE.name());
  82     }
  83
  84     @Test
  85     public void statusCodeEmptyWhenNotPassed() {
  86         SpyLogger spy = createSpy();
  87         new SLF4JLoggerWrapper(spy).audit(AuditData.builder().build());
  88         assertNull(spy.mdc().get(STATUS_CODE));
  89     }
  90
  91     @Test
  92     public void responseCodeAvailableWhenPassed() {
  93         final String responseCode = "SpyResponse";
  94         SpyLogger spy = createSpy();
  95         new SLF4JLoggerWrapper(spy).audit(AuditData.builder().responseCode(responseCode).build());
  96         assertEquals(spy.mdc().get(RESPONSE_CODE), responseCode);
  97     }
  98
  99     @Test
 100     public void responseCodeEmptyWhenNotPassed() {
 101         SpyLogger spy = createSpy();
 102         new SLF4JLoggerWrapper(spy).audit(AuditData.builder().build());
 103         assertNull(spy.mdc().get(RESPONSE_CODE));
 104     }
 105
 106     @Test
 107     public void responseDescriptionAvailableWhenPassed() {
 108         final String responseDescription = "SpyDescription";
 109         SpyLogger spy = createSpy();
 110         new SLF4JLoggerWrapper(spy).audit(AuditData.builder().responseDescription(responseDescription).build());
 111         assertEquals(spy.mdc().get(RESPONSE_DESCRIPTION), responseDescription);
 112     }
 113
 114     @Test
 115     public void responseDescriptionEmptyWhenNotPassed() {
 116         SpyLogger spy = createSpy();
 117         new SLF4JLoggerWrapper(spy).audit(AuditData.builder().build());
 118         assertNull(spy.mdc().get(RESPONSE_DESCRIPTION));
 119     }
 120
 121     @Test
 122     public void clientIpAddressAvailableWhenPassed() {
 123         final String ipAddress = "10.56.20.20";
 124         SpyLogger spy = createSpy();
 125         new SLF4JLoggerWrapper(spy).audit(AuditData.builder().clientIpAddress(ipAddress).build());
 126         assertEquals(spy.mdc().get(CLIENT_IP_ADDRESS), ipAddress);
 127     }
 128
 129     @Test
 130     public void clientIpAddressEmptyWhenNotPassed() {
 131         SpyLogger spy = createSpy();
 132         new SLF4JLoggerWrapper(spy).audit(AuditData.builder().build());
 133         assertNull(spy.mdc().get(CLIENT_IP_ADDRESS));
 134     }
 135
 136     @Test
 137     public void elapsedTimeEqualsDifferenceBetweenStartAndEnd() {
 138         SpyLogger spy = createSpy();
 139         final long diff = 1024;
 140         long start = System.currentTimeMillis();
 141         long end = start + diff;
 142         new SLF4JLoggerWrapper(spy).audit(AuditData.builder().startTime(start).endTime(end).build());
 143         assertEquals(spy.mdc().get(ELAPSED_TIME), Long.toString(diff));
 144     }
 145
 146     interface SpyLogger extends Logger {
 147
 148         Map<String, String> mdc();
 149     }
 150
 151     /**
 152      * Creates a in instance of Logger that can be used to track MDC changes as part of an invocation of
 153      * Logger.audit().
 154      *
 155      * @return object that implements {@link SpyLogger}
 156      */
 157     private static SpyLogger createSpy() {
 158
 159         // build a dynamic proxy to avoid implementing the long list of Logger methods
 160         // when we actually need just Logger.info() with the audit marker
 161         ClassLoader classLoader = Thread.currentThread().getContextClassLoader();
 162         return SpyLogger.class.cast(
 163                 Proxy.newProxyInstance(classLoader, new Class<?>[]{SpyLogger.class}, new SpyingInvocationHandler()));
 164     }
 165
 166     private static class SpyingInvocationHandler implements InvocationHandler {
 167
 168         private Map<String, String> mdc;
 169
 170         @Override
 171         public Object invoke(Object proxy, Method method, Object[] args) {
 172
 173             // return the remembered MDC for spying
 174             if (method.getName().equals("mdc")) {
 175                 return mdc;
 176             }
 177
 178             // filter out everything that's not related to audit
 179             if (!method.getName().equals("info") || args.length == 0 || !args[0].equals(Markers.AUDIT)) {
 180                 throw new UnsupportedOperationException("Method " + method.getName() + " with arguments " +
 181                     Arrays.toString(args) + " wasn't supposed to be called");
 182             }
 183
 184             // remember the MDC that was active during the invocation
 185             mdc = MDC.getCopyOfContextMap();
 186
 187             return null;
 188         }
 189     }
 190 }