diff --git a/build.sbt b/build.sbt index 04c5dcc080b..094d7a42fe4 100644 --- a/build.sbt +++ b/build.sbt @@ -222,11 +222,13 @@ lazy val kernelApi = (project in file("kernel/kernel-api")) Test / javaOptions ++= Seq("-ea"), libraryDependencies ++= Seq( "org.roaringbitmap" % "RoaringBitmap" % "0.9.25", + "org.slf4j" % "slf4j-api" % "2.0.9", "com.fasterxml.jackson.core" % "jackson-databind" % "2.13.5" % "test", "org.scalatest" %% "scalatest" % scalaTestVersion % "test", "junit" % "junit" % "4.13" % "test", - "com.novocode" % "junit-interface" % "0.11" % "test" + "com.novocode" % "junit-interface" % "0.11" % "test", + "org.slf4j" % "slf4j-log4j12" % "2.0.9" % "test" ), javaCheckstyleSettings("kernel/dev/checkstyle.xml"), // Unidoc settings @@ -251,7 +253,8 @@ lazy val kernelDefaults = (project in file("kernel/kernel-defaults")) "org.scalatest" %% "scalatest" % scalaTestVersion % "test", "junit" % "junit" % "4.13" % "test", "commons-io" % "commons-io" % "2.8.0" % "test", - "com.novocode" % "junit-interface" % "0.11" % "test" + "com.novocode" % "junit-interface" % "0.11" % "test", + "org.slf4j" % "slf4j-log4j12" % "2.0.9" % "test" ), javaCheckstyleSettings("kernel/dev/checkstyle.xml"), // Unidoc settings diff --git a/kernel/kernel-api/src/main/java/io/delta/kernel/internal/TableImpl.java b/kernel/kernel-api/src/main/java/io/delta/kernel/internal/TableImpl.java index 8ee6ff0b756..b295101889a 100644 --- a/kernel/kernel-api/src/main/java/io/delta/kernel/internal/TableImpl.java +++ b/kernel/kernel-api/src/main/java/io/delta/kernel/internal/TableImpl.java @@ -25,9 +25,8 @@ import io.delta.kernel.internal.fs.Path; import io.delta.kernel.internal.snapshot.SnapshotManager; -import io.delta.kernel.internal.util.Logging; -public class TableImpl implements Table, Logging { +public class TableImpl implements Table { public static Table forPath(TableClient tableClient, String path) throws TableNotFoundException { // Resolve the path to fully qualified table path using the `TableClient` APIs diff --git a/kernel/kernel-api/src/main/java/io/delta/kernel/internal/replay/LogReplay.java b/kernel/kernel-api/src/main/java/io/delta/kernel/internal/replay/LogReplay.java index 691a07fa288..0d5a5a1144f 100644 --- a/kernel/kernel-api/src/main/java/io/delta/kernel/internal/replay/LogReplay.java +++ b/kernel/kernel-api/src/main/java/io/delta/kernel/internal/replay/LogReplay.java @@ -36,7 +36,6 @@ import io.delta.kernel.internal.fs.Path; import io.delta.kernel.internal.lang.Lazy; import io.delta.kernel.internal.snapshot.LogSegment; -import io.delta.kernel.internal.util.Logging; import io.delta.kernel.internal.util.Tuple2; /** @@ -56,7 +55,7 @@ * - {@link #getAddFilesAsColumnarBatches}: return all active (not tombstoned) AddFiles as * {@link ColumnarBatch}s */ -public class LogReplay implements Logging { +public class LogReplay { /** Read schema when searching for the latest Protocol and Metadata. */ public static final StructType PROTOCOL_METADATA_READ_SCHEMA = new StructType() diff --git a/kernel/kernel-api/src/main/java/io/delta/kernel/internal/snapshot/SnapshotManager.java b/kernel/kernel-api/src/main/java/io/delta/kernel/internal/snapshot/SnapshotManager.java index 2d4c075a5f8..7adc5c360c4 100644 --- a/kernel/kernel-api/src/main/java/io/delta/kernel/internal/snapshot/SnapshotManager.java +++ b/kernel/kernel-api/src/main/java/io/delta/kernel/internal/snapshot/SnapshotManager.java @@ -22,6 +22,9 @@ import java.util.stream.Collectors; import java.util.stream.LongStream; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + import io.delta.kernel.Snapshot; import io.delta.kernel.TableNotFoundException; import io.delta.kernel.client.TableClient; @@ -35,15 +38,15 @@ import io.delta.kernel.internal.fs.Path; import io.delta.kernel.internal.lang.ListUtils; import io.delta.kernel.internal.util.FileNames; -import io.delta.kernel.internal.util.Logging; import io.delta.kernel.internal.util.Tuple2; import static io.delta.kernel.internal.fs.Path.getName; import static io.delta.kernel.internal.util.Preconditions.checkArgument; -public class SnapshotManager - implements Logging { +public class SnapshotManager { public SnapshotManager() {} + private static final Logger logger = LoggerFactory.getLogger(SnapshotManager.class); + /** * - Verify the versions are contiguous. * - Verify the versions start with `expectedStartVersion` if it's specified. @@ -98,7 +101,7 @@ private CloseableIterator listFrom( TableClient tableClient, long startVersion) throws IOException { - logDebug(String.format("startVersion: %s", startVersion)); + logger.debug("startVersion: {}", startVersion); return tableClient .getFileSystemClient() .listFrom(FileNames.listingPrefix(logPath, startVersion)); @@ -158,7 +161,7 @@ protected final Optional> listDeltaAndCheckpointFiles( TableClient tableClient, long startVersion, Optional versionToLoad) { - logDebug(String.format("startVersion: %s, versionToLoad: %s", startVersion, versionToLoad)); + logger.debug("startVersion: {}, versionToLoad: {}", startVersion, versionToLoad); return listFromOrNone( logPath, @@ -225,9 +228,9 @@ private SnapshotImpl createSnapshot( TableClient tableClient) { final String startingFromStr = initSegment .checkpointVersionOpt - .map(v -> String.format(" starting from checkpoint version %s.", v)) + .map(v -> String.format("starting from checkpoint version %s.", v)) .orElse("."); - logInfo(() -> String.format("Loading version %s%s", initSegment.version, startingFromStr)); + logger.info("Loading version {} {}", initSegment.version, startingFromStr); return new SnapshotImpl( logPath, @@ -324,13 +327,13 @@ protected Optional getLogSegmentForVersion( // recursive call to [[getLogSegmentForVersion]] below (same as before the refactor). newFiles = Collections.emptyList(); } - logDebug(() -> + logger.atDebug().setMessage(() -> String.format( "newFiles: %s", Arrays.toString(newFiles.stream() .map(x -> new Path(x.getPath()).getName()).toArray()) ) - ); + ).log(); if (newFiles.isEmpty() && !startCheckpointOpt.isPresent()) { // We can't construct a snapshot because the directory contained no usable commit @@ -356,7 +359,7 @@ protected Optional getLogSegmentForVersion( final List checkpoints = checkpointsAndDeltas._1; final List deltas = checkpointsAndDeltas._2; - logDebug(() -> + logger.atDebug().setMessage(() -> String.format( "\ncheckpoints: %s\ndeltas: %s", Arrays.toString(checkpoints.stream().map( @@ -364,23 +367,24 @@ protected Optional getLogSegmentForVersion( Arrays.toString(deltas.stream().map( x -> new Path(x.getPath()).getName()).toArray()) ) - ); + ).log(); // Find the latest checkpoint in the listing that is not older than the versionToLoad final CheckpointInstance maxCheckpoint = versionToLoadOpt.map(CheckpointInstance::new) .orElse(CheckpointInstance.MAX_VALUE); - logDebug(String.format("lastCheckpoint: %s", maxCheckpoint)); + logger.debug("lastCheckpoint: {}", maxCheckpoint); final List checkpointFiles = checkpoints .stream() .map(f -> new CheckpointInstance(f.getPath())) .collect(Collectors.toList()); - logDebug(() -> - String.format("checkpointFiles: %s", Arrays.toString(checkpointFiles.toArray()))); + logger.atDebug().setMessage(() -> + String.format("checkpointFiles: %s", Arrays.toString(checkpointFiles.toArray())) + ).log(); final Optional newCheckpointOpt = Checkpointer.getLatestCompleteCheckpointFromList(checkpointFiles, maxCheckpoint); - logDebug(String.format("newCheckpointOpt: %s", newCheckpointOpt)); + logger.debug("newCheckpointOpt: {}", newCheckpointOpt); final long newCheckpointVersion = newCheckpointOpt .map(c -> c.version) @@ -415,7 +419,7 @@ protected Optional getLogSegmentForVersion( return -1L; }); - logDebug(String.format("newCheckpointVersion: %s", newCheckpointVersion)); + logger.debug("newCheckpointVersion: {}", newCheckpointVersion); // TODO: we can calculate deltasAfterCheckpoint and deltaVersions more efficiently // If there is a new checkpoint, start new lineage there. If `newCheckpointVersion` is -1, @@ -427,13 +431,13 @@ protected Optional getLogSegmentForVersion( new Path(fileStatus.getPath())) > newCheckpointVersion) .collect(Collectors.toList()); - logDebug(() -> + logger.atDebug().setMessage(() -> String.format( "deltasAfterCheckpoint: %s", Arrays.toString(deltasAfterCheckpoint.stream().map( x -> new Path(x.getPath()).getName()).toArray()) ) - ); + ).log(); // todo again naming confusing (specify after checkpoint?) final LinkedList deltaVersionsAfterCheckpoint = deltasAfterCheckpoint @@ -441,9 +445,10 @@ protected Optional getLogSegmentForVersion( .map(fileStatus -> FileNames.deltaVersion(new Path(fileStatus.getPath()))) .collect(Collectors.toCollection(LinkedList::new)); - logDebug(() -> + logger.atDebug().setMessage(() -> String.format("deltaVersions: %s", - Arrays.toString(deltaVersionsAfterCheckpoint.toArray()))); + Arrays.toString(deltaVersionsAfterCheckpoint.toArray())) + ).log(); // We may just be getting a checkpoint file after the filtering if (!deltaVersionsAfterCheckpoint.isEmpty()) { diff --git a/kernel/kernel-api/src/main/java/io/delta/kernel/internal/util/Logging.java b/kernel/kernel-api/src/main/java/io/delta/kernel/internal/util/Logging.java deleted file mode 100644 index 754918f1c57..00000000000 --- a/kernel/kernel-api/src/main/java/io/delta/kernel/internal/util/Logging.java +++ /dev/null @@ -1,38 +0,0 @@ -/* - * Copyright (2023) The Delta Lake Project Authors. - * - * 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 io.delta.kernel.internal.util; - -import java.util.function.Supplier; - -// TODO re-enable proper logging -public interface Logging { - - default void logInfo(String msg) { - // System.out.println(this.getClass() + " :: " + msg); - } - - default void logInfo(Supplier msg) { - // System.out.println(this.getClass() + " :: " + msg.get()); - } - - default void logDebug(String msg) { - // System.out.println(this.getClass() + " :: " + msg); - } - - default void logDebug(Supplier msg) { - // System.out.println(this.getClass() + " :: " + msg.get()); - } -} diff --git a/kernel/kernel-api/src/test/resources/log4j.properties b/kernel/kernel-api/src/test/resources/log4j.properties new file mode 100644 index 00000000000..6a2aa9ad82e --- /dev/null +++ b/kernel/kernel-api/src/test/resources/log4j.properties @@ -0,0 +1,44 @@ +# +# Copyright (2023) The Delta Lake Project Authors. +# 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. +# +# +# Licensed to the Apache Software Foundation (ASF) under one or more +# contributor license agreements. See the NOTICE file distributed with +# this work for additional information regarding copyright ownership. +# The ASF licenses this file to You 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. + +# Set everything to be logged to the file target/unit-tests.log +test.appender=file +log4j.rootCategory=info, ${test.appender} +log4j.appender.file=org.apache.log4j.FileAppender +log4j.appender.file.append=true +log4j.appender.file.file=target/unit-tests.log +log4j.appender.file.layout=org.apache.log4j.PatternLayout +log4j.appender.file.layout.ConversionPattern=%d{yy/MM/dd HH:mm:ss.SSS} %t %p %c{1}: %m%n + +# Tests that launch java subprocesses can set the "test.appender" system property to +# "console" to avoid having the child process's logs overwrite the unit test's +# log file. +log4j.appender.console=org.apache.log4j.ConsoleAppender +log4j.appender.console.target=System.err +log4j.appender.console.layout=org.apache.log4j.PatternLayout +log4j.appender.console.layout.ConversionPattern=%t: %m%n diff --git a/kernel/kernel-defaults/src/test/resources/log4j.properties b/kernel/kernel-defaults/src/test/resources/log4j.properties new file mode 100644 index 00000000000..6a2aa9ad82e --- /dev/null +++ b/kernel/kernel-defaults/src/test/resources/log4j.properties @@ -0,0 +1,44 @@ +# +# Copyright (2023) The Delta Lake Project Authors. +# 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. +# +# +# Licensed to the Apache Software Foundation (ASF) under one or more +# contributor license agreements. See the NOTICE file distributed with +# this work for additional information regarding copyright ownership. +# The ASF licenses this file to You 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. + +# Set everything to be logged to the file target/unit-tests.log +test.appender=file +log4j.rootCategory=info, ${test.appender} +log4j.appender.file=org.apache.log4j.FileAppender +log4j.appender.file.append=true +log4j.appender.file.file=target/unit-tests.log +log4j.appender.file.layout=org.apache.log4j.PatternLayout +log4j.appender.file.layout.ConversionPattern=%d{yy/MM/dd HH:mm:ss.SSS} %t %p %c{1}: %m%n + +# Tests that launch java subprocesses can set the "test.appender" system property to +# "console" to avoid having the child process's logs overwrite the unit test's +# log file. +log4j.appender.console=org.apache.log4j.ConsoleAppender +log4j.appender.console.target=System.err +log4j.appender.console.layout=org.apache.log4j.PatternLayout +log4j.appender.console.layout.ConversionPattern=%t: %m%n