org.neo4j.kernel.impl.api.index.LoggingPhaseTracker Maven / Gradle / Ivy
Go to download
Show more of this group Show more artifacts with this name
Show all versions of neo4j-kernel Show documentation
Show all versions of neo4j-kernel Show documentation
Neo4j kernel is a lightweight, embedded Java database designed to
store data structured as graphs rather than tables. For more
information, see http://neo4j.org.
/*
* Copyright (c) "Neo4j"
* Neo4j Sweden AB [https://neo4j.com]
*
* This file is part of Neo4j.
*
* Neo4j is free software: you can redistribute it and/or modify
* it under the terms of the GNU General Public License as published by
* the Free Software Foundation, either version 3 of the License, or
* (at your option) any later version.
*
* This program is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU General Public License for more details.
*
* You should have received a copy of the GNU General Public License
* along with this program. If not, see times = new EnumMap<>(Phase.class);
private Phase currentPhase;
private long timeEnterPhase;
private boolean stopped;
private long lastPeriodReport = -1;
LoggingPhaseTracker(InternalLog log) {
this(PERIOD_INTERVAL, log, Clock.systemUTC());
}
@VisibleForTesting
LoggingPhaseTracker(long periodIntervalInSeconds, InternalLog log, Clock clock) {
this.periodInterval = TimeUnit.SECONDS.toMillis(periodIntervalInSeconds);
this.log = log;
this.clock = clock;
for (Phase phase : Phase.values()) {
times.put(phase, new Logger(phase));
}
}
@Override
public void enterPhase(Phase phase) {
if (stopped) {
throw new IllegalStateException("Trying to report a new phase after phase tracker has been stopped.");
}
if (phase != currentPhase) {
long now = logCurrentTime();
currentPhase = phase;
timeEnterPhase = now;
if (lastPeriodReport == -1) {
lastPeriodReport = now;
}
long millisSinceLastPeriodReport = now - lastPeriodReport;
if (millisSinceLastPeriodReport >= periodInterval) {
// Report period
periodReport(millisSinceLastPeriodReport);
lastPeriodReport = now;
}
}
}
@Override
public void registerTime(Phase phase, long millis) {
Preconditions.checkState(!stopped, "Trying to report a new phase after phase tracker has been stopped.");
logTime(phase, millis);
}
@Override
public void stop() {
stopped = true;
logCurrentTime();
currentPhase = null;
finalReport();
}
EnumMap times() {
return times;
}
private void finalReport() {
log.debug(MESSAGE_PREFIX + mainReportString("Final"));
}
private void periodReport(long millisSinceLastPeriodReport) {
String periodReportString = periodReportString(millisSinceLastPeriodReport);
String mainReportString = mainReportString("Total");
log.debug(MESSAGE_PREFIX + mainReportString + ", " + periodReportString);
}
private String mainReportString(String title) {
StringJoiner joiner = new StringJoiner(", ", title + ": ", "");
times.values().forEach(logger -> reportToJoiner(joiner, logger));
return joiner.toString();
}
private String periodReportString(long millisSinceLastPeriodReport) {
long secondsSinceLastPeriodReport = TimeUnit.MILLISECONDS.toSeconds(millisSinceLastPeriodReport);
StringJoiner joiner = new StringJoiner(", ", "Last " + secondsSinceLastPeriodReport + " sec: ", "");
times.values().stream().map(Logger::period).forEach(period -> {
reportToJoiner(joiner, period);
period.reset();
});
return joiner.toString();
}
private static void reportToJoiner(StringJoiner joiner, Counter counter) {
if (counter.nbrOfReports > 0) {
joiner.add(counter.toString());
}
}
private long logCurrentTime() {
long now = clock.millis();
if (currentPhase != null) {
logTime(currentPhase, now - timeEnterPhase);
}
return now;
}
private void logTime(Phase phase, long timeMillis) {
Logger logger = times.get(phase);
logger.log(timeMillis);
}
public static class Logger extends Counter {
final Counter periodCounter;
private Logger(Phase phase) {
super(phase);
periodCounter = new Counter(phase);
periodCounter.reset();
}
@Override
void log(long timeMillis) {
super.log(timeMillis);
periodCounter.log(timeMillis);
}
Counter period() {
return periodCounter;
}
}
public static class Counter {
private final Phase phase;
long totalTime;
long nbrOfReports;
long maxTime;
long minTime;
Counter(Phase phase) {
this.phase = phase;
}
void log(long timeMillis) {
totalTime += timeMillis;
nbrOfReports++;
maxTime = Math.max(maxTime, timeMillis);
minTime = Math.min(minTime, timeMillis);
}
void reset() {
totalTime = 0;
nbrOfReports = 0;
maxTime = Long.MIN_VALUE;
minTime = Long.MAX_VALUE;
}
@Override
public String toString() {
StringJoiner joiner = new StringJoiner(", ", phase + "[", "]");
if (nbrOfReports == 0) {
addToString("nbrOfReports", nbrOfReports, joiner, false);
} else if (nbrOfReports == 1) {
addToString("totalTime", totalTime, joiner, true);
} else {
long avgTime = totalTime / nbrOfReports;
addToString("totalTime", totalTime, joiner, true);
addToString("avgTime", avgTime, joiner, true);
addToString("minTime", minTime, joiner, true);
addToString("maxTime", maxTime, joiner, true);
addToString("nbrOfReports", nbrOfReports, joiner, false);
}
return joiner.toString();
}
static void addToString(String name, long measurement, StringJoiner joiner, boolean isTime) {
String measurementString;
if (isTime) {
long timeInNanos = TimeUnit.MILLISECONDS.toNanos(measurement);
measurementString = TimeUtil.nanosToString(timeInNanos);
} else {
measurementString = Long.toString(measurement);
}
joiner.add(String.format("%s=%s", name, measurementString));
}
}
}