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 [http://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( Log log )
{
this( PERIOD_INTERVAL, log, Clock.systemUTC() );
}
@VisibleForTesting
LoggingPhaseTracker( long periodIntervalInSeconds, Log 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.info( 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 ) );
}
}
}