kernel.core: change logger to tracer.

The logger generates a large amount of repeated data, this should go in
a trace. Additional data is also stored, but it is faster if tracing
is disabled as the string is not generated.

This should reduce the build log file sizes noticeably.

Change-Id: I7e1c2a799b9386be5872fe7ac3a3e4686ae416c7
Signed-off-by: Matthew Khouzam <matthew.khouzam@ericsson.com>
Reviewed-on: https://git.eclipse.org/r/98173
Reviewed-by: Genevieve Bastien <gbastien+lttng@versatic.net>
Tested-by: Genevieve Bastien <gbastien+lttng@versatic.net>
Reviewed-by: Hudson CI

diff --git a/analysis/org.eclipse.tracecompass.analysis.os.linux.core/src/org/eclipse/tracecompass/analysis/os/linux/core/cpuusage/KernelCpuUsageAnalysis.java b/analysis/org.eclipse.tracecompass.analysis.os.linux.core/src/org/eclipse/tracecompass/analysis/os/linux/core/cpuusage/KernelCpuUsageAnalysis.java
index 0fb4f3135daa9a1127255883ece9b38dccb3f650..833a19ea2829c5fbe0dd16c0d1042215aaf54509 100644 (file)
--- a/analysis/org.eclipse.tracecompass.analysis.os.linux.core/src/org/eclipse/tracecompass/analysis/os/linux/core/cpuusage/KernelCpuUsageAnalysis.java
+++ b/analysis/org.eclipse.tracecompass.analysis.os.linux.core/src/org/eclipse/tracecompass/analysis/os/linux/core/cpuusage/KernelCpuUsageAnalysis.java
@@ -20,6 +20,8 @@ import java.util.List;
 import java.util.Map;
 import java.util.Map.Entry;
 import java.util.Set;
+import java.util.logging.Level;
+import java.util.logging.Logger;
 
 import org.eclipse.jdt.annotation.NonNull;
 import org.eclipse.jdt.annotation.Nullable;
@@ -29,6 +31,9 @@ import org.eclipse.tracecompass.analysis.os.linux.core.trace.IKernelAnalysisEven
 import org.eclipse.tracecompass.analysis.os.linux.core.trace.IKernelTrace;
 import org.eclipse.tracecompass.analysis.os.linux.core.trace.KernelEventLayoutRequirement;
 import org.eclipse.tracecompass.common.core.NonNullUtils;
+import org.eclipse.tracecompass.common.core.log.TraceCompassLog;
+import org.eclipse.tracecompass.common.core.log.TraceCompassLogUtils;
+import org.eclipse.tracecompass.common.core.log.TraceCompassLogUtils.ScopeLog;
 import org.eclipse.tracecompass.internal.analysis.os.linux.core.Activator;
 import org.eclipse.tracecompass.internal.analysis.os.linux.core.kernel.Attributes;
 import org.eclipse.tracecompass.statesystem.core.ITmfStateSystem;
@@ -75,6 +80,8 @@ public class KernelCpuUsageAnalysis extends TmfStateSystemAnalysisModule {
         LAYOUT_REQUIREMENT = new KernelEventLayoutRequirement(ImmutableSet.of((l) -> l.eventSchedSwitch()), PriorityLevel.MANDATORY);
     }
 
+    private static final Logger LOGGER = TraceCompassLog.getLogger(KernelCpuUsageAnalysis.class);
+
     private static IKernelAnalysisEventLayout getLayout(@Nullable ITmfTrace trace) {
         IKernelAnalysisEventLayout layout;
 
@@ -187,7 +194,7 @@ public class KernelCpuUsageAnalysis extends TmfStateSystemAnalysisModule {
             return map;
         }
 
-        try {
+        try (ScopeLog scopeLog = new ScopeLog(LOGGER, Level.FINE, "KernelCpuUsageAnalysis#getCpuUsageInRange")) { //$NON-NLS-1$
             /* Get the list of quarks for each CPU and CPU's TIDs */
             int cpusNode = cpuSs.getQuarkAbsolute(Attributes.CPUS);
             Map<Integer, List<Integer>> tidsPerCpu = new HashMap<>();
@@ -237,8 +244,9 @@ public class KernelCpuUsageAnalysis extends TmfStateSystemAnalysisModule {
                      * those times
                      */
                     if (tid == startThread || startThread == -1) {
-                        long runningTime = kernelStartState.get(currentThreadQuark).getEndTime() - kernelStartState.get(currentThreadQuark).getStartTime();
-                        long runningEnd = kernelStartState.get(currentThreadQuark).getEndTime();
+                        ITmfStateInterval threadState = kernelStartState.get(currentThreadQuark);
+                        long runningTime = threadState.getEndTime() - threadState.getStartTime();
+                        long runningEnd = threadState.getEndTime();
 
                         countAtStart = interpolateCount(countAtStart, startTime, runningEnd, runningTime);
                     }
@@ -262,10 +270,22 @@ public class KernelCpuUsageAnalysis extends TmfStateSystemAnalysisModule {
 
                     long currentCount = countAtEnd - countAtStart;
                     if (currentCount < 0) {
-                        Activator.getDefault().logWarning(String.format("Negative count: start %d, end %d", countAtStart, countAtEnd)); //$NON-NLS-1$
+                        TraceCompassLogUtils.traceInstant(LOGGER, Level.FINE, "Negative count", //$NON-NLS-1$
+                                "CPU", curCpuName, //$NON-NLS-1$
+                                "tid", curTidName, //$NON-NLS-1$
+                                "startTime", startTime, //$NON-NLS-1$
+                                "endTime", endTime, //$NON-NLS-1$
+                                "countAtStart", countAtStart, //$NON-NLS-1$
+                                "countAtEnd", countAtEnd); //$NON-NLS-1$
                         currentCount = 0;
                     } else if (currentCount > endTime - startTime) {
-                        Activator.getDefault().logWarning(String.format("CPU Usage: Spent more time on CPU than allowed: %s spent %d when max should be %d", curTidName, currentCount, endTime - startTime)); //$NON-NLS-1$
+                        TraceCompassLogUtils.traceInstant(LOGGER, Level.FINE, "CPU usage over 100%", //$NON-NLS-1$
+                                "CPU", curCpuName, //$NON-NLS-1$
+                                "tid", curTidName, //$NON-NLS-1$
+                                "startTime", startTime, //$NON-NLS-1$
+                                "CPU time", currentCount, //$NON-NLS-1$
+                                "elapsed time", endTime - startTime, //$NON-NLS-1$
+                                "usage", currentCount * 100.0 / (endTime - startTime)); //$NON-NLS-1$
                         currentCount = 0;
                     }
                     cpuTotal += currentCount;
@@ -338,7 +358,7 @@ public class KernelCpuUsageAnalysis extends TmfStateSystemAnalysisModule {
         IKernelAnalysisEventLayout layout = getLayout(trace);
         Set<TmfAbstractAnalysisRequirement> reqs = LAYOUT_REQ_MAP.get(layout);
         if (reqs.isEmpty()) {
-            reqs= ImmutableSet.of(LAYOUT_REQUIREMENT.instanciateRequirements(layout));
+            reqs = ImmutableSet.of(LAYOUT_REQUIREMENT.instanciateRequirements(layout));
             LAYOUT_REQ_MAP.putAll(layout, reqs);
         }
         return reqs;