// Copyright 2018 The Bazel Authors. All rights reserved. // // Licensed under the Apache License, Version 2.0 (the "License"); // you may not use this file except in compliance with the License. // You may obtain a copy of the License at // // http://www.apache.org/licenses/LICENSE-2.0 // // Unless required by applicable law or agreed to in writing, software // distributed under the License is distributed on an "AS IS" BASIS, // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. // See the License for the specific language governing permissions and // limitations under the License. package com.google.devtools.build.lib.util; import static com.google.common.truth.Truth.assertThat; import static com.google.devtools.build.lib.testutil.MoreAsserts.assertThrows; import static java.nio.charset.StandardCharsets.UTF_8; import com.google.common.base.Strings; import java.io.BufferedReader; import java.io.File; import java.io.FileInputStream; import java.io.FileOutputStream; import java.io.IOException; import java.io.InputStreamReader; import java.io.OutputStreamWriter; import java.nio.file.DirectoryStream; import java.nio.file.Files; import java.nio.file.Path; import java.nio.file.Paths; import java.text.SimpleDateFormat; import java.time.Clock; import java.time.Instant; import java.time.ZoneId; import java.time.ZoneOffset; import java.util.Arrays; import java.util.Date; import java.util.Optional; import java.util.TimeZone; import java.util.logging.Formatter; import java.util.logging.Level; import java.util.logging.LogRecord; import org.junit.Rule; import org.junit.Test; import org.junit.rules.TemporaryFolder; import org.junit.runner.RunWith; import org.junit.runners.JUnit4; /** Tests for the {@link SimpleLogHandler} class. */ @RunWith(JUnit4.class) public final class SimpleLogHandlerTest { @Rule public TemporaryFolder tmp = new TemporaryFolder(); @Test public void testPrefix() throws Exception { SimpleLogHandler handler = SimpleLogHandler.builder() .setPrefix(tmp.getRoot() + File.separator + "hello_world_%u%h%%_") .build(); handler.publish(new LogRecord(Level.SEVERE, "Hello world")); // To open the log file. assertThat(handler.getCurrentLogFilePath().get().toString()) .startsWith(tmp.getRoot() + File.separator + "hello_world_%u%h%%_"); } @Test public void testPatternVariables() throws Exception { String username = System.getProperty("user.name"); if (Strings.isNullOrEmpty(username)) { username = "unknown_user"; } String hostname = SimpleLogHandler.getLocalHostnameFirstComponent(); SimpleLogHandler handler = SimpleLogHandler.builder() .setPrefix(tmp.getRoot() + File.separator + "hello_") .setPattern("world_%u%%%h_") .build(); handler.publish(new LogRecord(Level.SEVERE, "Hello world")); // To open the log file. assertThat(handler.getCurrentLogFilePath().get().toString()) .startsWith( tmp.getRoot() + File.separator + "hello_world_" + username + "%" + hostname + "_"); } @Test public void testPatternInvalidVariable() throws Exception { assertThrows( IllegalArgumentException.class, () -> SimpleLogHandler.builder().setPattern("hello_%t").build()); } @Test public void testExtensionDefaults() throws Exception { SimpleLogHandler handler = SimpleLogHandler.builder().setPrefix(tmp.getRoot() + File.separator + "hello").build(); handler.publish(new LogRecord(Level.SEVERE, "Hello world")); // To open the log file. assertThat(handler.getCurrentLogFilePath().get().toString()) .endsWith("." + SimpleLogHandler.getPidString()); } @Test public void testExtensionSetter() throws Exception { SimpleLogHandler handler1 = SimpleLogHandler.builder() .setPrefix(tmp.getRoot() + File.separator + "hello") .setExtension("xyz") .build(); handler1.publish(new LogRecord(Level.SEVERE, "Hello world")); // To open the log file. assertThat(handler1.getCurrentLogFilePath().get().toString()).endsWith(".xyz"); } private static final class FakeClock extends Clock { private Instant now; private final ZoneId zone; FakeClock(Instant now, ZoneId zone) { this.now = now; this.zone = zone; } void set(Instant now) { this.now = now; } @Override public Instant instant() { return now; } @Override public ZoneId getZone() { return zone; } @Override public Clock withZone(ZoneId zone) { return new FakeClock(this.now, zone); } } @Test public void testTimestamp() throws Exception { Instant instant = Instant.parse("2015-09-01T15:17:54Z"); FakeClock clock = new FakeClock(instant, ZoneOffset.UTC); SimpleDateFormat dateFormat = new SimpleDateFormat(SimpleLogHandler.DEFAULT_TIMESTAMP_FORMAT); dateFormat.setTimeZone(TimeZone.getTimeZone(ZoneOffset.UTC)); SimpleLogHandler handler = SimpleLogHandler.builder() .setPrefix(tmp.getRoot() + File.separator + "hello") .setClockForTesting(clock) .build(); handler.publish(new LogRecord(Level.SEVERE, "Hello world")); // To open the log file. assertThat(dateFormat.format(Date.from(instant))).isEqualTo("20150901-151754."); assertThat(handler.getCurrentLogFilePath().get().toString()).contains("20150901-151754."); } private static final class TrivialFormatter extends Formatter { @Override public String format(LogRecord rec) { return formatMessage(rec) + "\n"; } } @Test public void testPublish() throws Exception { SimpleLogHandler handler = SimpleLogHandler.builder() .setPrefix(tmp.getRoot() + File.separator + "hello") .setFormatter(new TrivialFormatter()) .build(); handler.publish(new LogRecord(Level.SEVERE, "Hello world")); // To open the log file. Path logPath = handler.getCurrentLogFilePath().get(); handler.close(); assertThat(new String(Files.readAllBytes(logPath), UTF_8)).isEqualTo("Hello world\n"); } @Test public void testSymbolicLinkDefaults() throws Exception { Path symlinkPath = Paths.get(tmp.getRoot().toString(), "hello"); Files.createFile(symlinkPath); // Expected to delete the file at symlinkPath and replace with a symlink to the log. SimpleLogHandler handler = SimpleLogHandler.builder().setPrefix(symlinkPath.toString()).build(); handler.publish(new LogRecord(Level.SEVERE, "Hello world")); // To open the log file. assertThat(handler.getSymbolicLinkPath().toString()).isEqualTo(symlinkPath.toString()); assertThat(Files.isSymbolicLink(handler.getSymbolicLinkPath())).isTrue(); assertThat(Files.readSymbolicLink(handler.getSymbolicLinkPath()).toString()) .isEqualTo(handler.getCurrentLogFilePath().get().getFileName().toString()); } @Test public void testSymbolicLinkSetter() throws Exception { SimpleLogHandler handler = SimpleLogHandler.builder() .setPrefix(tmp.getRoot() + File.separator + "hello") .setSymlink("bye") .build(); handler.publish(new LogRecord(Level.SEVERE, "Hello world")); // To open the log file. assertThat(handler.getSymbolicLinkPath().toString()) .isEqualTo(tmp.getRoot() + File.separator + "bye"); assertThat(Files.isSymbolicLink(handler.getSymbolicLinkPath())).isTrue(); assertThat(Files.readSymbolicLink(handler.getSymbolicLinkPath()).toString()) .isEqualTo(handler.getCurrentLogFilePath().get().getFileName().toString()); } @Test public void testSymbolicLinkInvalidPath() throws Exception { SimpleLogHandler.Builder builder = SimpleLogHandler.builder() .setPrefix(tmp.getRoot() + File.separator + "hello") .setSymlink("bye/bye"); // Invalid symlink path (not at top level of log directory). assertThrows(IllegalArgumentException.class, () -> builder.build()); } @Test public void testLogLevelEqualPublished() throws Exception { SimpleLogHandler handler = SimpleLogHandler.builder() .setPrefix(tmp.getRoot() + File.separator + "info") .setLogLevel(Level.INFO) .build(); handler.publish(new LogRecord(Level.INFO, "Hello")); Optional logPath = handler.getCurrentLogFilePath(); handler.close(); assertThat(Files.size(logPath.get())).isGreaterThan(0L); } @Test public void testLogLevelHigherPublished() throws Exception { SimpleLogHandler handler = SimpleLogHandler.builder() .setPrefix(tmp.getRoot() + File.separator + "info") .setLogLevel(Level.INFO) .build(); handler.publish(new LogRecord(Level.WARNING, "Hello")); Optional logPath = handler.getCurrentLogFilePath(); handler.close(); assertThat(Files.size(logPath.get())).isGreaterThan(0L); } @Test public void testLogLevelLowerNotPublished() throws Exception { SimpleLogHandler handler = SimpleLogHandler.builder() .setPrefix(tmp.getRoot() + File.separator + "info") .setLogLevel(Level.INFO) .build(); handler.publish(new LogRecord(Level.FINE, "Hello")); Optional logPath = handler.getCurrentLogFilePath(); handler.close(); assertThat(logPath.isPresent()).isFalse(); } @Test public void testLogLevelDefaultAllPublished() throws Exception { SimpleLogHandler handler = SimpleLogHandler.builder().setPrefix(tmp.getRoot() + File.separator + "all").build(); handler.publish(new LogRecord(Level.FINEST, "Hello")); Optional logPath = handler.getCurrentLogFilePath(); handler.close(); assertThat(Files.size(logPath.get())).isGreaterThan(0L); } @Test public void testRotateLimitBytes() throws Exception { FakeClock clock = new FakeClock(Instant.parse("2018-01-01T12:00:00Z"), ZoneOffset.UTC); SimpleLogHandler handler = SimpleLogHandler.builder() .setPrefix(tmp.getRoot() + File.separator + "limits") .setFormatter(new TrivialFormatter()) .setRotateLimitBytes(16) .setClockForTesting(clock) .build(); Path symlinkPath = handler.getSymbolicLinkPath(); handler.publish(new LogRecord(Level.SEVERE, "1234567" /* 8 bytes including "\n" */)); Path firstLogPath = handler.getCurrentLogFilePath().get(); clock.set(Instant.parse("2018-01-01T12:00:01Z")); // Ensure the next file has a different name. handler.publish(new LogRecord(Level.SEVERE, "1234567" /* 8 bytes including "\n" */)); Path secondLogPath = handler.getCurrentLogFilePath().get(); handler.publish(new LogRecord(Level.SEVERE, "1234567" /* 8 bytes including "\n" */)); handler.close(); assertThat(Files.isSymbolicLink(symlinkPath)).isTrue(); assertThat(Files.readSymbolicLink(symlinkPath).toString()) .isEqualTo(secondLogPath.getFileName().toString()); assertThat(Files.size(firstLogPath)).isEqualTo(16L /* including two "\n" */); assertThat(Files.size(secondLogPath)).isEqualTo(8L /* including "\n" */); try (DirectoryStream dirStream = Files.newDirectoryStream(tmp.getRoot().toPath())) { assertThat(dirStream).hasSize(3); } } private Path newFileWithContent(String name, String content) throws IOException { File file = tmp.newFile(name); try (OutputStreamWriter writer = new OutputStreamWriter(new FileOutputStream(file.getPath()), UTF_8)) { writer.write(content); } return file.toPath(); } private Path newFileOfSize(String name, int size) throws IOException { char[] buf = new char[size]; Arrays.fill(buf, '\n'); return newFileWithContent(name, new String(buf)); } @Test public void testOpenInAppendMode() throws Exception { Path logPath = newFileWithContent("hello.20150901-151754.log", "Previous logs\n"); Instant instant = Instant.parse("2015-09-01T15:17:54Z"); FakeClock clock = new FakeClock(instant, ZoneOffset.UTC); SimpleLogHandler handler = SimpleLogHandler.builder() .setPrefix(tmp.getRoot() + File.separator + "hello") .setPattern(".") .setExtension("log") .setFormatter(new TrivialFormatter()) .setClockForTesting(clock) .build(); handler.publish(new LogRecord(Level.SEVERE, "New logs")); assertThat(handler.getCurrentLogFilePath().get().toString()).isEqualTo(logPath.toString()); handler.close(); try (BufferedReader logReader = new BufferedReader(new InputStreamReader(new FileInputStream(logPath.toFile()), UTF_8))) { assertThat(logReader.readLine()).isEqualTo("Previous logs"); assertThat(logReader.readLine()).isEqualTo("New logs"); } } @Test public void testTotalLimit() throws Exception { String username = System.getProperty("user.name"); if (Strings.isNullOrEmpty(username)) { username = "unknown_user"; } String hostname = SimpleLogHandler.getLocalHostnameFirstComponent(); String baseFilename = "hello." + hostname + "." + username + ".log.java."; Path nonLog = newFileOfSize("non_log", 16); Path missingDate = newFileOfSize(baseFilename + ".123", 16); Path invalidExtension = newFileOfSize(baseFilename + "19900101-120000.invalid", 16); Path oldDeleted1 = newFileOfSize(baseFilename + "19900101-120000.123", 16); Path oldDeleted2 = newFileOfSize(baseFilename + "19950101-120000.123", 16); Path keptThenDeleted = newFileOfSize(baseFilename + "19990101-120000.123", 16); Path kept = newFileOfSize(baseFilename + "19990606-060000.123", 16); FakeClock clock = new FakeClock(Instant.parse("2018-01-01T12:00:00Z"), ZoneOffset.UTC); SimpleLogHandler handler = SimpleLogHandler.builder() .setPrefix(tmp.getRoot() + File.separator + "hello") .setPattern(".%h.%u.log.java.") .setFormatter(new TrivialFormatter()) .setRotateLimitBytes(16) .setTotalLimitBytes(40) .setClockForTesting(clock) .build(); // Print 8 bytes into the log file. Opening the log file triggers deletion of old logs. handler.publish(new LogRecord(Level.SEVERE, "1234567" /* 8 bytes including "\n" */)); // We expect handler to delete all but 32 = 40 - 8 bytes worth of old log files. assertThat(Files.exists(nonLog)).isTrue(); assertThat(Files.exists(missingDate)).isTrue(); assertThat(Files.exists(invalidExtension)).isTrue(); assertThat(Files.exists(oldDeleted1)).isFalse(); assertThat(Files.exists(oldDeleted2)).isFalse(); assertThat(Files.exists(keptThenDeleted)).isTrue(); assertThat(Files.exists(kept)).isTrue(); handler.publish(new LogRecord(Level.SEVERE, "1234567" /* 8 bytes including "\n" */)); Path currentLogPath = handler.getCurrentLogFilePath().get(); handler.close(); // We expect another old log file to be deleted after rotation. assertThat(Files.exists(keptThenDeleted)).isFalse(); assertThat(Files.exists(kept)).isTrue(); assertThat(Files.exists(currentLogPath)).isTrue(); } }