Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Log histograms with -Dorg.enso.persist.Logger.level=debug #8881

Merged
merged 2 commits into from
Jan 29, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions build.sbt
Original file line number Diff line number Diff line change
Expand Up @@ -1105,6 +1105,7 @@ lazy val `persistance` = (project in file("lib/java/persistance"))
frgaalJavaCompilerSetting,
Compile / javacOptions := ((Compile / javacOptions).value),
libraryDependencies ++= Seq(
"org.slf4j" % "slf4j-api" % slf4jVersion,
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Bye, bye "no dependencies" of lib/java/persitance project...

"org.netbeans.api" % "org-openide-util-lookup" % netbeansApiVersion,
"junit" % "junit" % junitVersion % Test,
"com.github.sbt" % "junit-interface" % junitIfVersion % Test
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -9,8 +9,7 @@
import java.util.IdentityHashMap;
import java.util.Map;
import java.util.function.Function;
import java.util.logging.Level;
import java.util.logging.Logger;
import org.slf4j.Logger;

final class PerGenerator {
static final byte[] HEADER = new byte[] {0x0a, 0x0d, 0x03, 0x0f};
Expand All @@ -31,7 +30,7 @@ private PerGenerator(
}

static byte[] writeObject(Object obj, Function<Object, Object> writeReplace) throws IOException {
var histogram = PerUtils.LOG.isLoggable(Level.FINE) ? new Histogram() : null;
var histogram = PerUtils.LOG.isDebugEnabled() ? new Histogram() : null;
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Whether or not we will log is decided up-front before creating new Histogram(). Once the instance is created, it is clear we will log whatever it will have collected at the end.


var out = new ByteArrayOutputStream();
var data = new DataOutputStream(out);
Expand Down Expand Up @@ -140,16 +139,14 @@ private void dump(Logger log, int length) {
return a.getValue()[0] - b.getValue()[0];
});

log.fine("==== Top Bytes & Counts of Classes =====");
log.debug("==== Top Bytes & Counts of Classes =====");
for (var i = 0; i < list.size(); i++) {
if (i == 30) {
break;
}
var elem = list.get(list.size() - 1 - i);
log.log(
Level.FINE,
" {0} {1} {2}",
new Object[] {elem.getValue()[0], elem.getValue()[1], elem.getKey().getName()});
log.debug(
" " + elem.getValue()[0] + " " + elem.getValue()[1] + " " + elem.getKey().getName());
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Unfortunately the {0} {1} {2} format doesn't work with sfl4j. Sad outcome of using two different logging system throughout the project.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I believe the correct way to do this in slf4j is just use empty brackets {} instead of {0}. As an example, look into

"Failed to delete the database file. Attempt #{}. File does not exist [{}].",

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Concatenating strings manually relies on standard Java mechanism rather than relying on the logging framework semantics. As it is guaranteed the message is going to be printed, I opted for the generic mechanism known to work.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It is fine for this case. But generally, you should avoid string concatenation for logs. If you do string concatenation, the concatenation is evaluated before log.debug method is called even if the DEBUG is disabled.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It is fine for this case.

Yes, it is absolutely fine in this case as we know we are going to log.

}
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,6 @@
import java.util.Map;
import java.util.Objects;
import java.util.function.Function;
import java.util.logging.Level;
import org.enso.persist.Persistance.Input;
import org.enso.persist.Persistance.Reference;

Expand Down Expand Up @@ -213,7 +212,7 @@ static Object readIndirect(InputCache cache, PerMap map, Input in) throws IOExce
sb.append("\nare they equal: ").append(bothObjectsAreTheSame);
var ex = new IOException(sb.toString());
if (bothObjectsAreTheSame) {
PerUtils.LOG.log(Level.WARNING, sb.toString(), ex);
PerUtils.LOG.warn(sb.toString(), ex);
} else {
throw raise(RuntimeException.class, ex);
}
Expand Down
Original file line number Diff line number Diff line change
@@ -1,11 +1,12 @@
package org.enso.persist;

import java.util.logging.Logger;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

final class PerUtils {
private PerUtils() {}

static final Logger LOG = Logger.getLogger(Persistance.class.getPackageName());
static final Logger LOG = LoggerFactory.getLogger(Persistance.class.getPackageName());

@SuppressWarnings("unchecked")
static <E extends Throwable> E raise(Class<E> clazz, Throwable t) throws E {
Expand Down
Loading