Skip to content

Commit

Permalink
RDS logging
Browse files Browse the repository at this point in the history
  • Loading branch information
breitnw committed Jul 11, 2024
1 parent dff1661 commit 698de95
Show file tree
Hide file tree
Showing 11 changed files with 834 additions and 461 deletions.
20 changes: 20 additions & 0 deletions src/main/java/org/prlprg/AppConfig.java
Original file line number Diff line number Diff line change
Expand Up @@ -49,6 +49,14 @@ public final class AppConfig extends Config {
public static final OptimizationLogLevel OPTIMIZATION_LOG_LEVEL =
get("OPTIMIZATION_LOG_LEVEL", OptimizationLogLevel.NONE);

/**
* How to log RDS reads and writes. Useful for diagnosing misalignments between input and output
* streams.
*
* <p><b>Default:</b>: {@link RDSLogLevel#NONE}
*/
public static final RDSLogLevel RDS_LOG_LEVEL = get("RDS_LOG_LEVEL", RDSLogLevel.NONE);

public enum CfgDebugLevel {
/** No extra checks. */
NONE,
Expand All @@ -74,6 +82,18 @@ public enum OptimizationLogLevel implements Comparable<OptimizationLogLevel> {
/** Log every optimization pass <i>and</i> every inner {@link CodeObject} it's applied to. */
ALL,
}

public enum RDSLogLevel implements Comparable<RDSLogLevel> {
/** Don't log any RDS input or output */
NONE,
/** Only log RDS input and output directly from tests */
TEST,
/**
* Log general RDS input and output, such as from base initialization (WARNING: logging general
* output may cause very large files to be generated, or even lead to out-of-memory errors)
*/
GENERAL,
}
}

/**
Expand Down
13 changes: 13 additions & 0 deletions src/main/java/org/prlprg/rds/Flags.java
Original file line number Diff line number Diff line change
Expand Up @@ -82,6 +82,19 @@ public int unpackRefIndex() {
return flags >> 8;
}

/**
* Returns a new Flags identical to this one, but with the hasAttr bit set according to
* hasAttributes.
*/
public Flags withAttributes(boolean hasAttributes) {
return new Flags(this.flags & ~ATTR_MASK | (hasAttributes ? ATTR_MASK : 0));
}

/** Returns a new Flags identical to this one, but with the hasTag bit set according to hasTag. */
public Flags withTag(boolean hasTag) {
return new Flags(this.flags & ~TAG_MASK | (hasTag ? TAG_MASK : 0));
}

@Override
public String toString() {
return "Flags{"
Expand Down
3 changes: 2 additions & 1 deletion src/main/java/org/prlprg/rds/GNURByteCodeEncoderFactory.java
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
package org.prlprg.rds;

import com.google.common.primitives.ImmutableIntArray;
import org.jetbrains.annotations.NotNull;
import org.prlprg.bc.Bc;
import org.prlprg.bc.BcCode;
import org.prlprg.bc.BcInstr;
Expand Down Expand Up @@ -37,7 +38,7 @@ public ImmutableIntArray buildRaw() {
}

/** Converts the arguments of the provided BcInstr to a "raw" format; i.e. an array of integers */
public int[] args(BcInstr instr) {
public int[] args(@NotNull BcInstr instr) {
return switch (instr) {
case BcInstr.Goto i -> new int[] {mapping.extract(i.label())};
case BcInstr.BrIfNot i -> new int[] {i.ast().idx(), mapping.extract(i.label())};
Expand Down
121 changes: 32 additions & 89 deletions src/main/java/org/prlprg/rds/RDSInputStream.java
Original file line number Diff line number Diff line change
Expand Up @@ -8,9 +8,11 @@

class RDSInputStream implements Closeable {
private final DataInputStream in;
private final RDSLogger logger;

RDSInputStream(InputStream in) {
RDSInputStream(InputStream in, RDSLogger logger) {
this.in = new DataInputStream(in);
this.logger = logger;
}

@Override
Expand All @@ -24,114 +26,55 @@ public void close() throws IOException {
* @return the next byte of data, or -1 if the end of the stream is reached.
* @throws IOException if an I/O error occurs.
*/
public int readRaw() throws IOException {
return in.read();
public int readRaw(String desc) throws IOException {
var input = in.read();
logger.log(input, desc);
return input;
}

public byte readByte() throws IOException {
return in.readByte();
public byte readByte(String desc) throws IOException {
var input = in.readByte();
logger.log(input, desc);
return input;
}

public int readInt() throws IOException {
return in.readInt();
public int readInt(String desc) throws IOException {
var input = in.readInt();
logger.log(input, desc);
return input;
}

public double readDouble() throws IOException {
return in.readDouble();
public double readDouble(String desc) throws IOException {
var input = in.readDouble();
logger.log(input, desc);
return input;
}

public String readString(int natEncSize, Charset charset) throws IOException {
public String readString(int natEncSize, Charset charset, String desc) throws IOException {
var buf = new byte[natEncSize];
in.readFully(buf, 0, natEncSize);
return new String(buf, charset);
var input = new String(buf, charset);
logger.log(input, desc);
return input;
}

public int[] readInts(int length) throws IOException {
public int[] readInts(int length, String desc) throws IOException {
int[] ints = new int[length];
for (int i = 0; i < length; i++) {
var n = readInt();
var n = in.readInt();
ints[i] = n;
}
logger.logAll(ints, desc);
return ints;
}

public double[] readDoubles(int length) throws IOException {
double[] ints = new double[length];
public double[] readDoubles(int length, String desc) throws IOException {
double[] doubles = new double[length];
for (int i = 0; i < length; i++) {
var n = readDouble();
ints[i] = n;
var n = in.readDouble();
doubles[i] = n;
}
return ints;
}
}

class RDSInputStreamVerbose extends RDSInputStream {
RDSInputStreamVerbose(InputStream in) {
super(in);
System.out.println("\n===================== READING STREAM ====================\n");
StackTraceElement caller = Thread.currentThread().getStackTrace()[4];
System.out.println("Testing: " + caller + "\n");
}

@Override
public int readRaw() throws IOException {
var res = super.readRaw();
StackTraceElement caller = Thread.currentThread().getStackTrace()[2];
System.out.printf("%-20s | reading raw: %d%n", caller.getMethodName(), res);
return res;
}

@Override
public byte readByte() throws IOException {
var res = super.readByte();
StackTraceElement caller = Thread.currentThread().getStackTrace()[2];
System.out.printf(
"%-20s | reading byte: %d (%s)%n",
caller.getMethodName(), res, Integer.toBinaryString(res));
return res;
}

@Override
public int readInt() throws IOException {
var res = super.readInt();
StackTraceElement caller = Thread.currentThread().getStackTrace()[2];
System.out.printf(
"%-20s | reading int: %d (%s)%n",
caller.getMethodName(), res, Integer.toBinaryString(res));
return res;
}

@Override
public double readDouble() throws IOException {
var res = super.readDouble();
StackTraceElement caller = Thread.currentThread().getStackTrace()[2];
System.out.printf("%-20s | reading double: %f%n", caller.getMethodName(), res);
return res;
}

@Override
public String readString(int natEncSize, Charset charset) throws IOException {
var res = super.readString(natEncSize, charset);
StackTraceElement caller = Thread.currentThread().getStackTrace()[2];
System.out.printf("%-20s | reading String: %s%n", caller.getMethodName(), res);
return res;
}

@Override
public int[] readInts(int length) throws IOException {
StackTraceElement caller = Thread.currentThread().getStackTrace()[2];
System.out.printf("%-20s | reading %d ints...%n", caller.getMethodName(), length);
var res = super.readInts(length);
System.out.printf("%-20s | done reading ints%n", caller.getMethodName());
return res;
}

@Override
public double[] readDoubles(int length) throws IOException {
StackTraceElement caller = Thread.currentThread().getStackTrace()[2];
System.out.printf("%-20s | reading %d doubles...%n", caller.getMethodName(), length);
var res = super.readDoubles(length);
System.out.printf("%-20s | done reading doubles%n", caller.getMethodName());
return res;
logger.logAll(doubles, desc);
return doubles;
}
}
116 changes: 116 additions & 0 deletions src/main/java/org/prlprg/rds/RDSLogger.java
Original file line number Diff line number Diff line change
@@ -0,0 +1,116 @@
package org.prlprg.rds;

import java.util.*;
import java.util.function.Supplier;
import java.util.logging.*;
import org.prlprg.AppConfig;

final class RDSLogger {
private final StringBuilder output = new StringBuilder();
private final boolean shouldLog;
private int indentLevel;

/**
* @param name a description of the read or write, printed at the start of logging
*/
RDSLogger(String name, AppConfig.RDSLogLevel logLevel) {
this.indentLevel = 0;
this.shouldLog = AppConfig.RDS_LOG_LEVEL.compareTo(logLevel) >= 0;
logString(() -> name);
}

/** Globally enables log output to the provided handler */
public static void addHandler(Handler handler) {
var logger = Logger.getLogger(RDSLogger.class.getName());
logger.addHandler(handler);
handler.setLevel(Level.FINE);
}

/**
* Logs a lazily-evaluated String with the current indent level with Level.FINE.
*
* @param msg a thunk supplying the String to be logged.
*/
private void logString(Supplier<String> msg) {
if (shouldLog) {
int level = this.indentLevel;
String indent = String.join("", Collections.nCopies(level, " "));
output.append(indent).append(msg.get()).append("\n");
}
}

/**
* Logs the reading or writing of a new SEXP by printing an identifier and increasing the
* indentation level by 1
*
* @param sexpIdent a String identifying the SEXP being logged
*/
public void push(String sexpIdent) {
logString(() -> sexpIdent + " {");
indentLevel++;
}

/**
* Logs the end of the reading or writing of a SEXP by printing a closing brace and decreasing the
* indentation level by 1
*/
public void pop() {
indentLevel--;
logString(() -> "}");
}

/**
* Lazily logs a value read from the input stream or written to the output stream, alongside a
* description of the value's usage
*
* @param <T> the type of the value to be logged
* @param value the value to be logged
* @param description a description of the value's usage
*/
public <T> void log(T value, String description) {
logString(
() ->
switch (value) {
case Integer i ->
String.format("%s: %d (%s)", description, i, Integer.toBinaryString(i));
case Byte b ->
String.format("%s: %d (%s)", description, b, Integer.toBinaryString(b));
default -> String.format("%s: %s", description, value);
});
}

/**
* Lazily logs an array of ints read from the input stream or written to the output stream,
* alongside a description of the array's usage
*
* @param ints the array to be logged
* @param description a description of the array's usage
*/
public void logAll(int[] ints, String description) {
logString(() -> String.format("%s: %s", description, Arrays.toString(ints)));
}

/**
* Lazily logs an array of doubles read from the input stream or written to the output stream,
* alongside a description of the array's usage
*
* @param doubles the array to be logged
* @param description a description of the array's usage
*/
public void logAll(double[] doubles, String description) {
logString(() -> String.format("%s: %s", description, Arrays.toString(doubles)));
}

/**
* Writes the RDS output collected thus far to the system logger at level {@code Level.FINE}. This
* is written in one go rather than in individual messages to preserve formatting and reduce
* metadata stored with each message.
*/
public void finish() {
if (shouldLog) {
Logger logger = Logger.getLogger(RDSLogger.class.getName());
logger.setLevel(Level.FINE);
logger.fine(output.toString());
}
}
}
Loading

0 comments on commit 698de95

Please sign in to comment.