Skip to content

Commit

Permalink
Allow usage of system timezone for database logs
Browse files Browse the repository at this point in the history 
Previously all database logs where using UTC only for time in all logs.
This PR will allow to change behaviour and use system timezone for all the logs
using newly introduced "log_timezone" database setting.

Current possible setting values are:
UTC(default value) - log in UTC;
SYSTEM - log in a system default timezone.
  • Loading branch information
@MishaDemianenko
MishaDemianenko committed Oct 20, 2017
1 parent a551841 commit 9e60e4b
Show file tree
Hide file tree
Showing 24 changed files with 369 additions and 50 deletions.
6 changes: 4 additions & 2 deletions community/bolt/src/main/java/org/neo4j/bolt/logging/BoltMessageLog.java
View file
Expand Up @@ -22,6 +22,7 @@

import java.io.File;
import java.io.IOException;
import java.time.ZoneId;
import java.time.format.DateTimeFormatter;
import java.util.concurrent.Executor;
import java.util.concurrent.TimeUnit;
Expand All @@ -42,12 +43,13 @@ public class BoltMessageLog extends LifecycleAdapter

private final Log inner;

public BoltMessageLog( FileSystemAbstraction fileSystem, File logFile, Executor executor ) throws IOException
public BoltMessageLog( FileSystemAbstraction fileSystem, ZoneId logTimeZone, File logFile, Executor executor ) throws IOException
{
RotatingFileOutputStreamSupplier outputStreamSupplier = new RotatingFileOutputStreamSupplier( fileSystem,
logFile, ROTATION_THRESHOLD_BYTES, ROTATION_DELAY_MS, MAX_ARCHIVES, executor );
DateTimeFormatter isoDateTimeFormatter = DateTimeFormatter.ISO_OFFSET_DATE_TIME;
FormattedLog formattedLog = FormattedLog.withUTCTimeZone().withDateTimeFormatter( isoDateTimeFormatter )
FormattedLog formattedLog = FormattedLog.withZoneId( logTimeZone )
.withDateTimeFormatter( isoDateTimeFormatter )
.toOutputStream( outputStreamSupplier );
formattedLog.setLevel( Level.DEBUG );

Expand Down
8 changes: 5 additions & 3 deletions community/bolt/src/main/java/org/neo4j/bolt/logging/BoltMessageLogging.java
View file
Expand Up @@ -19,11 +19,12 @@
*/
package org.neo4j.bolt.logging;

import io.netty.channel.Channel;

import java.io.File;
import java.time.ZoneId;
import java.util.concurrent.Executor;

import io.netty.channel.Channel;

import org.neo4j.graphdb.factory.GraphDatabaseSettings;
import org.neo4j.io.fs.FileSystemAbstraction;
import org.neo4j.kernel.configuration.Config;
Expand Down Expand Up @@ -64,7 +65,8 @@ private static BoltMessageLog createBoltMessageLog( FileSystemAbstraction fs, Jo
{
File boltLogFile = config.get( GraphDatabaseSettings.bolt_log_filename );
Executor executor = scheduler.executor( JobScheduler.Groups.boltLogRotation );
return new BoltMessageLog( fs, boltLogFile, executor );
ZoneId logTimeZoneId = config.get( GraphDatabaseSettings.log_timezone ).getZoneId();
return new BoltMessageLog( fs, logTimeZoneId, boltLogFile, executor );
}
catch ( Throwable t )
{
Expand Down
7 changes: 5 additions & 2 deletions community/consistency-check/src/main/java/org/neo4j/consistency/CheckConsistencyCommand.java
View file
Expand Up @@ -22,6 +22,7 @@
import java.io.File;
import java.io.IOException;
import java.nio.file.Path;
import java.time.ZoneId;
import java.util.HashMap;
import java.util.Map;
import java.util.Optional;
Expand All @@ -36,6 +37,7 @@
import org.neo4j.consistency.checking.full.CheckConsistencyConfig;
import org.neo4j.consistency.checking.full.ConsistencyCheckIncompleteException;
import org.neo4j.dbms.DatabaseManagementSystemSettings;
import org.neo4j.graphdb.factory.GraphDatabaseSettings;
import org.neo4j.helpers.Strings;
import org.neo4j.helpers.collection.MapUtil;
import org.neo4j.helpers.progress.ProgressMonitorFactory;
Expand Down Expand Up @@ -180,10 +182,11 @@ public void execute( String[] args ) throws IncorrectUsage, CommandFailed
{
File storeDir = backupPath.map( Path::toFile ).orElse( config.get( database_path ) );
checkDbState( storeDir, config );
ZoneId logTimeZone = config.get( GraphDatabaseSettings.log_timezone ).getZoneId();
ConsistencyCheckService.Result consistencyCheckResult = consistencyCheckService
.runFullConsistencyCheck( storeDir, config, ProgressMonitorFactory.textual( System.err ),
FormattedLogProvider.toOutputStream( System.out ), fileSystem, verbose,
reportDir.toFile(),
FormattedLogProvider.withZoneId( logTimeZone ).toOutputStream( System.out ),
fileSystem, verbose, reportDir.toFile(),
new CheckConsistencyConfig(
checkGraph, checkIndexes, checkLabelScanStore, checkPropertyOwners ) );

Expand Down
5 changes: 4 additions & 1 deletion community/consistency-check/src/main/java/org/neo4j/consistency/ConsistencyCheckTool.java
View file
Expand Up @@ -22,11 +22,13 @@
import java.io.File;
import java.io.IOException;
import java.io.PrintStream;
import java.time.ZoneId;
import java.util.List;
import java.util.Map;

import org.neo4j.consistency.checking.full.CheckConsistencyConfig;
import org.neo4j.consistency.checking.full.ConsistencyCheckIncompleteException;
import org.neo4j.graphdb.factory.GraphDatabaseSettings;
import org.neo4j.helpers.Args;
import org.neo4j.helpers.Strings;
import org.neo4j.helpers.collection.MapUtil;
Expand Down Expand Up @@ -111,7 +113,8 @@ ConsistencyCheckService.Result run( String... args ) throws ToolFailureException

checkDbState( storeDir, tuningConfiguration );

LogProvider logProvider = FormattedLogProvider.toOutputStream( systemOut );
ZoneId logTimeZone = tuningConfiguration.get( GraphDatabaseSettings.log_timezone ).getZoneId();
LogProvider logProvider = FormattedLogProvider.withZoneId( logTimeZone ).toOutputStream( systemOut );
try
{
return consistencyCheckService.runFullConsistencyCheck( storeDir, tuningConfiguration,
Expand Down
81 changes: 74 additions & 7 deletions ...unity/consistency-check/src/test/java/org/neo4j/consistency/ConsistencyCheckToolTest.java
View file
Expand Up @@ -19,26 +19,37 @@
*/
package org.neo4j.consistency;

import org.apache.commons.lang3.StringUtils;
import org.junit.Rule;
import org.junit.Test;
import org.junit.rules.RuleChain;
import org.mockito.ArgumentCaptor;
import org.mockito.Mockito;
import org.mockito.stubbing.Answer;

import java.io.BufferedReader;
import java.io.ByteArrayInputStream;
import java.io.ByteArrayOutputStream;
import java.io.File;
import java.io.FileWriter;
import java.io.IOException;
import java.io.InputStreamReader;
import java.io.PrintStream;
import java.time.ZoneOffset;
import java.util.Properties;

import org.junit.Rule;
import org.junit.Test;
import org.junit.rules.RuleChain;
import org.mockito.ArgumentCaptor;
import java.util.TimeZone;

import org.neo4j.consistency.ConsistencyCheckTool.ToolFailureException;
import org.neo4j.consistency.checking.full.CheckConsistencyConfig;
import org.neo4j.graphdb.GraphDatabaseService;
import org.neo4j.graphdb.Transaction;
import org.neo4j.graphdb.factory.GraphDatabaseSettings;
import org.neo4j.helpers.progress.ProgressMonitorFactory;
import org.neo4j.io.fs.DefaultFileSystemAbstraction;
import org.neo4j.io.fs.FileSystemAbstraction;
import org.neo4j.kernel.configuration.Config;
import org.neo4j.logging.LogProvider;
import org.neo4j.logging.LogTimeZone;
import org.neo4j.test.TestGraphDatabaseFactory;
import org.neo4j.test.rule.TestDirectory;
import org.neo4j.test.rule.fs.EphemeralFileSystemRule;
Expand Down Expand Up @@ -82,6 +93,38 @@ public void runsConsistencyCheck() throws Exception
anyBoolean(), any( CheckConsistencyConfig.class ) );
}

@Test
public void consistencyCheckerLogUseSystemTimezoneIfConfigurable() throws Exception
{
TimeZone defaultTimeZone = TimeZone.getDefault();
try
{
ConsistencyCheckService service = mock( ConsistencyCheckService.class );
Mockito.when( service.runFullConsistencyCheck( any( File.class ), any( Config.class ),
any( ProgressMonitorFactory.class ), any( LogProvider.class ), any( FileSystemAbstraction.class ),
eq( false ), any( CheckConsistencyConfig.class ) ) )
.then( (Answer<ConsistencyCheckService.Result>) invocationOnMock ->
{
LogProvider provider = invocationOnMock.getArgumentAt( 3, LogProvider.class );
provider.getLog( "test" ).info( "testMessage" );
return ConsistencyCheckService.Result.success( new File( StringUtils.EMPTY ) );
} );
File storeDir = storeDirectory.directory();
File configFile = storeDirectory.file( Config.DEFAULT_CONFIG_FILE_NAME );
Properties properties = new Properties();
properties.setProperty( GraphDatabaseSettings.log_timezone.name(), LogTimeZone.SYSTEM.name() );
properties.store( new FileWriter( configFile ), null );
String[] args = {storeDir.getPath(), "-config", configFile.getPath()};

checkLogRecordTimeZone( service, args, 5, "+0500" );
checkLogRecordTimeZone( service, args, -5, "-0500" );
}
finally
{
TimeZone.setDefault( defaultTimeZone );
}
}

@Test
public void appliesDefaultTuningConfigurationForConsistencyChecker() throws Exception
{
Expand Down Expand Up @@ -177,6 +220,24 @@ public void failWhenStoreWasNonCleanlyShutdown() throws Exception
runConsistencyCheckToolWith( fs.get(), storeDirectory.graphDbDir().getAbsolutePath() );
}

private void checkLogRecordTimeZone( ConsistencyCheckService service, String[] args, int i, String s )
throws ToolFailureException, IOException
{
TimeZone.setDefault( TimeZone.getTimeZone( ZoneOffset.ofHours( i ) ) );
ByteArrayOutputStream outputStream = new ByteArrayOutputStream();
PrintStream printStream = new PrintStream( outputStream );
runConsistencyCheckToolWith( service, printStream, args );
String logLine = readLogLine( outputStream );
assertTrue( logLine, logLine.contains( s ) );
}

private String readLogLine( ByteArrayOutputStream outputStream ) throws IOException
{
ByteArrayInputStream byteArrayInputStream = new ByteArrayInputStream( outputStream.toByteArray() );
BufferedReader bufferedReader = new BufferedReader( new InputStreamReader( byteArrayInputStream ) );
return bufferedReader.readLine();
}

private void createGraphDbAndKillIt() throws Exception
{
final GraphDatabaseService db = new TestGraphDatabaseFactory()
Expand All @@ -203,11 +264,17 @@ private void runConsistencyCheckToolWith( FileSystemAbstraction fileSystem, Stri

private void runConsistencyCheckToolWith( ConsistencyCheckService
consistencyCheckService, String... args ) throws ToolFailureException, IOException
{
runConsistencyCheckToolWith( consistencyCheckService, mock( PrintStream.class ), args );
}

private void runConsistencyCheckToolWith( ConsistencyCheckService
consistencyCheckService, PrintStream printStream, String... args ) throws ToolFailureException, IOException
{
try ( FileSystemAbstraction fileSystemAbstraction = new DefaultFileSystemAbstraction() )
{
new ConsistencyCheckTool( consistencyCheckService, fileSystemAbstraction, mock( PrintStream.class ),
mock( PrintStream.class ) ).run( args );
new ConsistencyCheckTool( consistencyCheckService, fileSystemAbstraction, printStream, printStream )
.run( args );
}
}
}
5 changes: 5 additions & 0 deletions community/kernel/src/main/java/org/neo4j/graphdb/factory/GraphDatabaseSettings.java
View file
Expand Up @@ -45,6 +45,7 @@
import org.neo4j.kernel.configuration.ssl.SslPolicyConfigValidator;
import org.neo4j.kernel.impl.cache.MonitorGc;
import org.neo4j.logging.Level;
import org.neo4j.logging.LogTimeZone;

import static org.neo4j.kernel.configuration.Settings.ANY;
import static org.neo4j.kernel.configuration.Settings.BOOLEAN;
Expand Down Expand Up @@ -300,6 +301,10 @@ public class GraphDatabaseSettings implements LoadableConfig
public static final Setting<Level> store_internal_log_level = setting( "dbms.logs.debug.level",
options( Level.class ), "INFO" );

@Description( "Database logs timezone." )
public static final Setting<LogTimeZone> log_timezone =
setting( "dbms.logs.timezone", options( LogTimeZone.class ), LogTimeZone.UTC.name() );

@Description( "Maximum time to wait for active transaction completion when rotating counts store" )
@Internal
public static final Setting<Duration> counts_store_rotation_timeout =
Expand Down
28 changes: 14 additions & 14 deletions community/kernel/src/main/java/org/neo4j/helpers/Format.java
View file
Expand Up @@ -29,6 +29,20 @@

public class Format
{
private static final String[] BYTE_SIZES = { "B", "kB", "MB", "GB" };

public static final String DATE_FORMAT = "yyyy-MM-dd HH:mm:ss.SSSZ";
public static final String TIME_FORMAT = "HH:mm:ss.SSS";

/**
* Default time zone is UTC (+00:00) so that comparing timestamped logs from different
* sources is an easier task.
*/
public static final TimeZone DEFAULT_TIME_ZONE = TimeZone.getTimeZone( "UTC" );

private static final ThreadLocalFormat DATE = new ThreadLocalFormat( DATE_FORMAT );
private static final ThreadLocalFormat TIME = new ThreadLocalFormat( TIME_FORMAT );

public static String date()
{
return date( DEFAULT_TIME_ZONE );
Expand Down Expand Up @@ -181,20 +195,6 @@ private Format()
// No instances
}

private static final String[] BYTE_SIZES = { "B", "kB", "MB", "GB" };

public static final String DATE_FORMAT = "yyyy-MM-dd HH:mm:ss.SSSZ";
public static final String TIME_FORMAT = "HH:mm:ss.SSS";

/**
* Default time zone is UTC (+00:00) so that comparing timestamped logs from different
* sources is an easier task.
*/
public static final TimeZone DEFAULT_TIME_ZONE = TimeZone.getTimeZone( "UTC" );

private static final ThreadLocalFormat DATE = new ThreadLocalFormat( DATE_FORMAT );
private static final ThreadLocalFormat TIME = new ThreadLocalFormat( TIME_FORMAT );

private static class ThreadLocalFormat extends ThreadLocal<DateFormat>
{
private final String format;
Expand Down
1 change: 1 addition & 0 deletions community/kernel/src/main/java/org/neo4j/kernel/impl/factory/PlatformModule.java
View file
Expand Up @@ -278,6 +278,7 @@ protected LogService createLogService( LogProvider userLogProvider )
builder.withLevel( debugContext, Level.DEBUG );
}
builder.withDefaultLevel( config.get( GraphDatabaseSettings.store_internal_log_level ) );
builder.withTimeZone( config.get( GraphDatabaseSettings.log_timezone ).getZoneId() );

File logFile = config.get( store_internal_log_path );
if ( !logFile.getParentFile().exists() )
Expand Down
14 changes: 12 additions & 2 deletions community/kernel/src/main/java/org/neo4j/kernel/impl/logging/StoreLogService.java
View file
Expand Up @@ -23,6 +23,8 @@
import java.io.File;
import java.io.IOException;
import java.io.OutputStream;
import java.time.ZoneId;
import java.time.ZoneOffset;
import java.util.HashMap;
import java.util.Map;
import java.util.concurrent.Executor;
Expand Down Expand Up @@ -53,6 +55,7 @@ public static class Builder
};
private Map<String, Level> logLevels = new HashMap<>();
private Level defaultLevel = Level.INFO;
private ZoneId timeZoneId = ZoneOffset.UTC;
private File debugLog;

private Builder()
Expand Down Expand Up @@ -94,6 +97,12 @@ public Builder withLevel( String context, Level level )
return this;
}

public Builder withTimeZone( ZoneId timeZoneId )
{
this.timeZoneId = timeZoneId;
return this;
}

public Builder withDefaultLevel( Level defaultLevel )
{
this.defaultLevel = defaultLevel;
Expand All @@ -112,7 +121,7 @@ public StoreLogService build( FileSystemAbstraction fileSystem ) throws IOExcept
{
throw new IllegalArgumentException( "Debug log can't be null; set its value using `withInternalLog`" );
}
return new StoreLogService( userLogProvider, fileSystem, debugLog, logLevels, defaultLevel,
return new StoreLogService( userLogProvider, fileSystem, debugLog, logLevels, defaultLevel, timeZoneId,
internalLogRotationThreshold, internalLogRotationDelay, maxInternalLogArchives, rotationExecutor,
rotationListener );
}
Expand Down Expand Up @@ -143,6 +152,7 @@ private StoreLogService( LogProvider userLogProvider,
File internalLog,
Map<String, Level> logLevels,
Level defaultLevel,
ZoneId logTimeZone,
long internalLogRotationThreshold,
long internalLogRotationDelay,
int maxInternalLogArchives,
Expand All @@ -154,7 +164,7 @@ private StoreLogService( LogProvider userLogProvider,
fileSystem.mkdirs( internalLog.getParentFile() );
}

final FormattedLogProvider.Builder internalLogBuilder = FormattedLogProvider.withUTCTimeZone()
final FormattedLogProvider.Builder internalLogBuilder = FormattedLogProvider.withZoneId( logTimeZone )
.withDefaultLogLevel( defaultLevel ).withLogLevels( logLevels );

FormattedLogProvider internalLogProvider;
Expand Down
5 changes: 4 additions & 1 deletion ...src/main/java/org/neo4j/kernel/impl/pagecache/ConfigurableStandalonePageCacheFactory.java
View file
Expand Up @@ -19,6 +19,8 @@
*/
package org.neo4j.kernel.impl.pagecache;

import java.time.ZoneId;

import org.neo4j.graphdb.factory.GraphDatabaseSettings;
import org.neo4j.io.fs.FileSystemAbstraction;
import org.neo4j.io.pagecache.PageCache;
Expand Down Expand Up @@ -65,7 +67,8 @@ public static PageCache createPageCache( FileSystemAbstraction fileSystem, PageC
PageCursorTracerSupplier pageCursorTracerSupplier, Config config )
{
config.augmentDefaults( GraphDatabaseSettings.pagecache_memory, "8M" );
FormattedLogProvider logProvider = FormattedLogProvider.toOutputStream( System.err );
ZoneId logTimeZone = config.get( GraphDatabaseSettings.log_timezone ).getZoneId();
FormattedLogProvider logProvider = FormattedLogProvider.withZoneId( logTimeZone ).toOutputStream( System.err );
ConfiguringPageCacheFactory pageCacheFactory = new ConfiguringPageCacheFactory(
fileSystem, config, pageCacheTracer, pageCursorTracerSupplier,
logProvider.getLog( PageCache.class ) );
Expand Down

0 comments on commit 9e60e4b

Please sign in to comment.