TracerAspect.java

/*
 * To change this license header, choose License Headers in Project Properties.
 * To change this template file, choose Tools | Templates
 * and open the template in the editor.
 */
package br.ufrgs.inf.prosoft.applicationtracer;

import br.ufrgs.inf.prosoft.jsonserialiser.JSONSerialiser;
import br.ufrgs.inf.prosoft.trace.Parameter;
import br.ufrgs.inf.prosoft.trace.Return;
import br.ufrgs.inf.prosoft.trace.Trace;
import br.ufrgs.inf.prosoft.trace.TraceConcrete;
import java.io.FileWriter;
import java.io.IOException;
import java.nio.file.Files;
import java.nio.file.Paths;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.List;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.Future;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.TimeoutException;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;

/**
 *
 * @author romulo
 */
@Aspect
public class TracerAspect {

    private static final boolean TRACER_ENABLE = System.getenv("TRACER_ENABLE") != null && System.getenv("TRACER_ENABLE").equals("true");
    private static final long TRACER_MINIMUM_EXECUTION_TIME = getMinimumExecutionTime();
    private static final String TRACER_TRACES = System.getenv("TRACER_TRACES") != null ? System.getenv("TRACER_TRACES") : "./traces";
    private static final String TRACER_BLACKLIST = System.getenv("TRACER_BLACKLIST") != null ? System.getenv("TRACER_BLACKLIST") : "./blacklist";
    private static final boolean TRACER_VERBOSE = System.getenv("TRACER_VERBOSE") == null || !System.getenv("TRACER_VERBOSE").equals("false");
    private static final String TRACER_LOG = System.getenv("TRACER_LOG");

    private static long getMinimumExecutionTime() {
        String minimumExecutionTime = System.getenv("TRACER_MINIMUM_EXECUTION_TIME");
        if (minimumExecutionTime == null) {
            return 0;
        }
        try {
            return Long.parseLong(minimumExecutionTime);
        } catch (NumberFormatException ex) {
            return 0;
        }
    }

    @Pointcut("execution(!void *(..)) && !within(br.ufrgs.inf.prosoft.applicationtracer..*)")
    public void anyMethodExecution() {
    }

    @Around("anyMethodExecution()")
    public Object serialiseMethodCall(ProceedingJoinPoint joinPoint) throws Throwable {
        if (!TRACER_ENABLE) {
            return joinPoint.proceed();
        }
        long startTime = System.currentTimeMillis();
        Object proceed = joinPoint.proceed();
        long endTime = System.currentTimeMillis();
        if (endTime - startTime < TRACER_MINIMUM_EXECUTION_TIME) {
            return proceed;
        }
        String longsignature = joinPoint.getSignature().toLongString();
        if (longsignature.contains("AjcClosure")) {
            return proceed;
        }
        List<String> blacklist;
        try {
            blacklist = Files.readAllLines(Paths.get(TRACER_BLACKLIST));
        } catch (IOException ex) {
            blacklist = new ArrayList<>();
        }
        if (blacklist.contains(longsignature)) {
            System.out.println("[ApplicationTracer] skipping " + longsignature);
            log(System.currentTimeMillis() + " [INFO   ] skipping " + longsignature);
            return proceed;
        }
        try {
            boolean verbose = TRACER_VERBOSE && endTime - startTime > 5;
            if (verbose) {
                System.out.print("[ApplicationTracer] tracing " + longsignature + "... ");
            }
            String[] split = longsignature.substring(0, longsignature.length() - 1).split("\\(");
            String[] modifiersReturnAndName = split[0].split(" ");
            String[] modifiers = Arrays.copyOf(modifiersReturnAndName, modifiersReturnAndName.length - 2);
            String methodName = modifiersReturnAndName[modifiersReturnAndName.length - 1];
            String returnType = modifiersReturnAndName[modifiersReturnAndName.length - 2];
            List<Parameter> parameters = new ArrayList<>();
            if (split.length > 1) {
                String[] parameterTypes = split[1].split(", ");
                Object[] parametersData = joinPoint.getArgs();
                for (int i = 0; i < parametersData.length; i++) {
                    parameters.add(new Parameter(parameterTypes[i], parametersData[i]));
                }
            }
            Return returnValue = new Return(returnType, proceed);
            String instance;
            try {
                instance = String.valueOf(joinPoint.getThis().hashCode());
            } catch (Exception ex) {
                instance = "s";
            }
            String userId = getUserId();
            Trace trace = new TraceConcrete(instance, Arrays.asList(modifiers), returnValue, methodName, parameters, startTime, endTime, userId);
            synchronized (TracerAspect.class) {
                startTime = System.currentTimeMillis();
                if (verbose) {
                    System.out.print(startTime + "... ");
                }
                ExecutorService service = Executors.newSingleThreadExecutor();
                Future<String> futureTrace = service.submit(() -> {
                    String jsonTrace = JSONSerialiser.serialise(trace);
                    jsonTrace += "\n";
                    return jsonTrace;
                });
                String jsonTrace;
                long middleTime;
                try {
                    jsonTrace = futureTrace.get(20, TimeUnit.SECONDS);
                    middleTime = System.currentTimeMillis();
                    if (verbose) {
                        System.out.print(middleTime + "... ");
                    }
                    try (FileWriter fileWriter = new FileWriter(TRACER_TRACES, true)) {
                        fileWriter.write(jsonTrace);
                    }
                    endTime = System.currentTimeMillis();
                    if (verbose) {
                        System.out.println(endTime);
                    }
                    log(System.currentTimeMillis() + " [INFO   ] " + startTime + " " + middleTime + " " + endTime + " " + longsignature);
                } catch (TimeoutException ex) {
                    log(System.currentTimeMillis() + " [WARNING] timeout " + longsignature);
                    System.err.println("[ApplicationTracer] tracing timeout on " + longsignature);
                }
            }
        } catch (Exception ex) {
            log("[SEVERE ] exception: " + ex);
            System.err.println("[ApplicationTracer] exception: " + ex);
        }
        return proceed;
    }

    private String getUserId() {
        try {
            Object contextHolder = Class.forName("org.springframework.security.core.context.SecurityContextHolder").newInstance();
            Object context = contextHolder.getClass().getMethod("getContext").invoke(contextHolder);
            Object auth = context.getClass().getMethod("getAuthentication").invoke(context);
            return (String) auth.getClass().getMethod("getName").invoke(auth);
        } catch (Exception ex) {
            return "";
        }
    }

    private void log(String message) {
        if (TRACER_LOG == null) {
            return;
        }
        try (FileWriter fileWriter = new FileWriter(TRACER_LOG, true)) {
            fileWriter.write(message + "\n");
        } catch (IOException ex) {
        }
    }
}