X-Git-Url: http://git.efficios.com/?a=blobdiff_plain;f=analysis%2Forg.eclipse.tracecompass.analysis.os.linux.core%2Fsrc%2Forg%2Feclipse%2Ftracecompass%2Fanalysis%2Fos%2Flinux%2Fcore%2Fcpuusage%2FKernelCpuUsageAnalysis.java;h=833a19ea2829c5fbe0dd16c0d1042215aaf54509;hb=e7fd1b0e45c991180fa36fa52997edcab4ecdd14;hp=0fb4f3135daa9a1127255883ece9b38dccb3f650;hpb=b075fbf02aed3f1a590389c062390399af1d3b91;p=deliverable%2Ftracecompass.git 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 0fb4f3135d..833a19ea28 100644 --- 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> 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 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;