[RocksJava] Logging JNI callback

Within this commit a new AbstractLogger was introduced
which pushes info log messages all the way up to Java.

java/Makefile

@@ -1,4 +1,5 @@
 NATIVE_JAVA_CLASSES = org.rocksdb.AbstractComparator\
+    org.rocksdb.AbstractLogger\
 	org.rocksdb.AbstractSlice\
 	org.rocksdb.BackupableDB\
 	org.rocksdb.BackupableDBOptions\
@@ -54,7 +55,8 @@ ifeq ($(PLATFORM), OS_MACOSX)
 ROCKSDB_JAR = rocksdbjni-$(ROCKSDB_MAJOR).$(ROCKSDB_MINOR).$(ROCKSDB_PATCH)-osx.jar
 endif
 
-JAVA_TESTS = org.rocksdb.BackupableDBOptionsTest\
+JAVA_TESTS = org.rocksdb.AbstractLoggerTest\
+    org.rocksdb.BackupableDBOptionsTest\
 	org.rocksdb.BackupableDBTest\
 	org.rocksdb.BlockBasedTableConfigTest\
 	org.rocksdb.CheckPointTest\

java/rocksjni/loggerjnicallback.cc

@@ -0,0 +1,167 @@
+// Copyright (c) 2014, Facebook, Inc.  All rights reserved.
+// This source code is licensed under the BSD-style license found in the
+// LICENSE file in the root directory of this source tree. An additional grant
+// of patent rights can be found in the PATENTS file in the same directory.
+//
+// This file implements the callback "bridge" between Java and C++ for
+// rocksdb::Comparator.
+
+#include "include/org_rocksdb_AbstractLogger.h"
+
+#include "rocksjni/loggerjnicallback.h"
+#include "rocksjni/portal.h"
+
+namespace rocksdb {
+
+LoggerJniCallback::LoggerJniCallback(
+    JNIEnv* env, jobject jAbstractLogger) {
+
+  const jint rs = env->GetJavaVM(&m_jvm);
+  assert(rs == JNI_OK);
+
+  // Note: we want to access the Java Logger instance
+  // across multiple method calls, so we create a global ref
+  m_jAbstractLogger = env->NewGlobalRef(jAbstractLogger);
+  m_jLogMethodId = AbstractLoggerJni::getLogMethodId(env);
+}
+
+/**
+ * Get JNIEnv for current native thread
+ */
+JNIEnv* LoggerJniCallback::getJniEnv() const {
+  JNIEnv *env;
+  jint rs = m_jvm->AttachCurrentThread(reinterpret_cast<void **>(&env), NULL);
+  assert(rs == JNI_OK);
+  return env;
+}
+
+void LoggerJniCallback::Logv(const char* format, va_list ap) {
+  // We implement this method because it is virtual but we don't
+  // use it because we need to know about the log level.
+}
+
+void LoggerJniCallback::Logv(const InfoLogLevel log_level,
+    const char* format, va_list ap) {
+  if (GetInfoLogLevel() <= log_level) {
+    JNIEnv* env = getJniEnv();
+    // We try twice: the first time with a fixed-size stack allocated buffer,
+    // and the second time with a much larger dynamically allocated buffer.
+    char buffer[500];
+    for (int iter = 0; iter < 2; iter++) {
+      char* base;
+      int bufsize;
+      if (iter == 0) {
+        bufsize = sizeof(buffer);
+        base = buffer;
+      } else {
+        bufsize = 30000;
+        base = new char[bufsize];
+      }
+      char* p = base;
+      char* limit = base + bufsize;
+      // Print the message
+      if (p < limit) {
+        va_list backup_ap;
+        va_copy(backup_ap, ap);
+        p += vsnprintf(p, limit - p, format, backup_ap);
+        va_end(backup_ap);
+      }
+      // Truncate to available space if necessary
+      if (p >= limit) {
+        if (iter == 0) {
+          continue;       // Try again with larger buffer
+        } else {
+          p = limit - 1;
+        }
+      }
+      assert(p < limit);
+      *p++ = '\0';
+
+      // determine InfoLogLevel java enum instance
+      jobject jlog_level;
+      switch(log_level) {
+        case rocksdb::InfoLogLevel::DEBUG_LEVEL:
+          jlog_level = InfoLogLevelJni::DEBUG_LEVEL(env);
+          break;
+        case rocksdb::InfoLogLevel::INFO_LEVEL:
+          jlog_level = InfoLogLevelJni::INFO_LEVEL(env);
+          break;
+        case rocksdb::InfoLogLevel::ERROR_LEVEL:
+          jlog_level = InfoLogLevelJni::ERROR_LEVEL(env);
+        case rocksdb::InfoLogLevel::FATAL_LEVEL:
+          jlog_level = InfoLogLevelJni::FATAL_LEVEL(env);
+        default:
+          jlog_level = InfoLogLevelJni::FATAL_LEVEL(env);
+          break;
+      }
+      // pass java string to callback handler
+      env->CallVoidMethod(
+          m_jAbstractLogger,
+          m_jLogMethodId,
+          jlog_level,
+          env->NewStringUTF(base));
+
+      if (base != buffer) {
+        delete[] base;
+      }
+      break;
+    }
+    m_jvm->DetachCurrentThread();
+  }
+}
+
+LoggerJniCallback::~LoggerJniCallback() {
+  JNIEnv* env = getJniEnv();
+  env->DeleteGlobalRef(m_jAbstractLogger);
+  m_jvm->DetachCurrentThread();
+}
+
+}  // namespace rocksdb
+
+/*
+ * Class:     org_rocksdb_AbstractLogger
+ * Method:    createNewLoggerOptions
+ * Signature: (J)V
+ */
+void Java_org_rocksdb_AbstractLogger_createNewLoggerOptions(
+    JNIEnv* env, jobject jobj, jlong joptions) {
+  rocksdb::LoggerJniCallback* c =
+      new rocksdb::LoggerJniCallback(env, jobj);
+  // set log level
+  c->SetInfoLogLevel(reinterpret_cast<rocksdb::Options*>
+      (joptions)->info_log_level);
+  std::shared_ptr<rocksdb::LoggerJniCallback> *pLoggerJniCallback =
+      new std::shared_ptr<rocksdb::LoggerJniCallback>;
+  *pLoggerJniCallback = std::shared_ptr<rocksdb::LoggerJniCallback>(c);
+  rocksdb::AbstractLoggerJni::setHandle(env, jobj, pLoggerJniCallback);
+}
+
+/*
+ * Class:     org_rocksdb_AbstractLogger
+ * Method:    createNewLoggerDbOptions
+ * Signature: (J)V
+ */
+void Java_org_rocksdb_AbstractLogger_createNewLoggerDbOptions(
+    JNIEnv* env, jobject jobj, jlong jdb_options) {
+  rocksdb::LoggerJniCallback* c =
+      new rocksdb::LoggerJniCallback(env, jobj);
+  // set log level
+  c->SetInfoLogLevel(reinterpret_cast<rocksdb::DBOptions*>
+      (jdb_options)->info_log_level);
+  std::shared_ptr<rocksdb::LoggerJniCallback> *pLoggerJniCallback =
+      new std::shared_ptr<rocksdb::LoggerJniCallback>;
+  *pLoggerJniCallback = std::shared_ptr<rocksdb::LoggerJniCallback>(c);
+  rocksdb::AbstractLoggerJni::setHandle(env, jobj, pLoggerJniCallback);
+}
+
+/*
+ * Class:     org_rocksdb_AbstractLogger
+ * Method:    disposeInternal
+ * Signature: (J)V
+ */
+void Java_org_rocksdb_AbstractLogger_disposeInternal(
+    JNIEnv* env, jobject jobj, jlong jhandle) {
+  std::shared_ptr<rocksdb::LoggerJniCallback> *handle =
+      reinterpret_cast<std::shared_ptr<rocksdb::LoggerJniCallback> *>(jhandle);
+  handle->reset();
+}

java/rocksjni/loggerjnicallback.h

@@ -0,0 +1,40 @@
+// Copyright (c) 2014, Facebook, Inc.  All rights reserved.
+// This source code is licensed under the BSD-style license found in the
+// LICENSE file in the root directory of this source tree. An additional grant
+// of patent rights can be found in the PATENTS file in the same directory.
+//
+// This file implements the callback "bridge" between Java and C++ for
+// rocksdb::Logger
+
+#ifndef JAVA_ROCKSJNI_LOGGERJNICALLBACK_H_
+#define JAVA_ROCKSJNI_LOGGERJNICALLBACK_H_
+
+#include <jni.h>
+#include <string>
+#include "port/port.h"
+#include "rocksdb/env.h"
+
+namespace rocksdb {
+
+  class LoggerJniCallback : public Logger {
+    public:
+      LoggerJniCallback(JNIEnv* env, jobject jAbstractLogger);
+      virtual ~LoggerJniCallback();
+      // Write an entry to the log file with the specified format.
+      virtual void Logv(const char* format, va_list ap);
+      // Write an entry to the log file with the specified log level
+      // and format.  Any log with level under the internal log level
+      // of *this (see @SetInfoLogLevel and @GetInfoLogLevel) will not be
+      // printed.
+      virtual void Logv(const InfoLogLevel log_level, const char* format, va_list ap);
+
+    protected:
+      JNIEnv* getJniEnv() const;
+    private:
+      JavaVM* m_jvm;
+      jobject m_jAbstractLogger;
+      jmethodID m_jLogMethodId;
+  };
+}
+
+#endif

java/rocksjni/options.cc

@@ -639,6 +639,19 @@ void Java_org_rocksdb_Options_setRateLimiter(
       reinterpret_cast<rocksdb::RateLimiter*>(jrate_limiter_handle));
 }
 
+/*
+ * Class:     org_rocksdb_Options
+ * Method:    setLogger
+ * Signature: (JJ)V
+ */
+void Java_org_rocksdb_Options_setLogger(
+    JNIEnv* env, jobject jobj, jlong jhandle, jlong jlogger_handle) {
+std::shared_ptr<rocksdb::LoggerJniCallback> *pLogger =
+      reinterpret_cast<std::shared_ptr<rocksdb::LoggerJniCallback> *>(
+          jlogger_handle);
+  reinterpret_cast<rocksdb::Options*>(jhandle)->info_log = *pLogger;
+}
+
 /*
  * Class:     org_rocksdb_Options
  * Method:    setInfoLogLevel
@@ -2935,6 +2948,19 @@ void Java_org_rocksdb_DBOptions_setRateLimiter(
       reinterpret_cast<rocksdb::RateLimiter*>(jrate_limiter_handle));
 }
 
+/*
+ * Class:     org_rocksdb_DBOptions
+ * Method:    setLogger
+ * Signature: (JJ)V
+ */
+void Java_org_rocksdb_DBOptions_setLogger(
+    JNIEnv* env, jobject jobj, jlong jhandle, jlong jlogger_handle) {
+  std::shared_ptr<rocksdb::LoggerJniCallback> *pLogger =
+      reinterpret_cast<std::shared_ptr<rocksdb::LoggerJniCallback> *>(
+          jlogger_handle);
+  reinterpret_cast<rocksdb::DBOptions*>(jhandle)->info_log = *pLogger;
+}
+
 /*
  * Class:     org_rocksdb_DBOptions
  * Method:    setInfoLogLevel

java/rocksjni/portal.h

@@ -21,6 +21,7 @@
 #include "rocksdb/utilities/backupable_db.h"
 #include "rocksdb/utilities/write_batch_with_index.h"
 #include "rocksjni/comparatorjnicallback.h"
+#include "rocksjni/loggerjnicallback.h"
 #include "rocksjni/writebatchhandlerjnicallback.h"
 
 namespace rocksdb {
@@ -655,6 +656,72 @@ class WriteEntryJni {
     }
 };
 
+class InfoLogLevelJni {
+ public:
+
+    // Get the DEBUG_LEVEL enum field of org.rocksdb.InfoLogLevel
+    static jobject DEBUG_LEVEL(JNIEnv* env) {
+      return getEnum(env, "DEBUG_LEVEL");
+    }
+
+    // Get the INFO_LEVEL enum field of org.rocksdb.InfoLogLevel
+    static jobject INFO_LEVEL(JNIEnv* env) {
+      return getEnum(env, "INFO_LEVEL");
+    }
+
+    // Get the WARN_LEVEL enum field of org.rocksdb.InfoLogLevel
+    static jobject WARN_LEVEL(JNIEnv* env) {
+      return getEnum(env, "WARN_LEVEL");
+    }
+
+    // Get the ERROR_LEVEL enum field of org.rocksdb.InfoLogLevel
+    static jobject ERROR_LEVEL(JNIEnv* env) {
+      return getEnum(env, "ERROR_LEVEL");
+    }
+
+    // Get the FATAL_LEVEL enum field of org.rocksdb.InfoLogLevel
+    static jobject FATAL_LEVEL(JNIEnv* env) {
+      return getEnum(env, "FATAL_LEVEL");
+    }
+
+ private:
+    // Get the java class id of org.rocksdb.WBWIRocksIterator.WriteType.
+    static jclass getJClass(JNIEnv* env) {
+      jclass jclazz = env->FindClass("org/rocksdb/InfoLogLevel");
+      assert(jclazz != nullptr);
+      return jclazz;
+    }
+
+    // Get an enum field of org.rocksdb.WBWIRocksIterator.WriteType
+    static jobject getEnum(JNIEnv* env, const char name[]) {
+      jclass jclazz = getJClass(env);
+      jfieldID jfid =
+          env->GetStaticFieldID(jclazz, name,
+          "Lorg/rocksdb/InfoLogLevel;");
+      assert(jfid != nullptr);
+      return env->GetStaticObjectField(jclazz, jfid);
+    }
+};
+
+// The portal class for org.rocksdb.AbstractLogger
+class AbstractLoggerJni : public RocksDBNativeClass<
+    std::shared_ptr<rocksdb::LoggerJniCallback>*, AbstractLoggerJni> {
+ public:
+  static jclass getJClass(JNIEnv* env) {
+    return RocksDBNativeClass::getJClass(env,
+        "org/rocksdb/AbstractLogger");
+  }
+
+  // Get the java method `name` of org.rocksdb.AbstractLogger.
+  static jmethodID getLogMethodId(JNIEnv* env) {
+    static jmethodID mid = env->GetMethodID(
+        getJClass(env), "log",
+        "(Lorg/rocksdb/InfoLogLevel;Ljava/lang/String;)V");
+    assert(mid != nullptr);
+    return mid;
+  }
+};
+
 class JniUtil {
  public:
     /*

java/src/main/java/org/rocksdb/AbstractLogger.java

@@ -0,0 +1,60 @@
+package org.rocksdb;
+
+/**
+ * <p>This class provides a custom logger functionality
+ * in Java which wraps {@code RocksDB} logging facilities.
+ * </p>
+ *
+ * <p>Using this class RocksDB can log with common
+ * Java logging APIs like Log4j or Slf4j without keeping
+ * database logs in the filesystem.</p>
+ */
+public abstract class AbstractLogger extends RocksObject {
+
+  /**
+   * <p>AbstractLogger constructor.</p>
+   *
+   * <p><strong>Important:</strong> the log level set within
+   * the {@link org.rocksdb.Options} instance will be used as
+   * maximum log level of RocksDB.</p>
+   *
+   * @param options {@link org.rocksdb.Options} instance.
+   */
+  public AbstractLogger(Options options) {
+    createNewLoggerOptions(options.nativeHandle_);
+  }
+
+  /**
+   * <p>AbstractLogger constructor.</p>
+   *
+   * <p><strong>Important:</strong> the log level set within
+   * the {@link org.rocksdb.DBOptions} instance will be used
+   * as maximum log level of RocksDB.</p>
+   *
+   * @param dboptions {@link org.rocksdb.DBOptions} instance.
+   */
+  public AbstractLogger(DBOptions dboptions) {
+    createNewLoggerDbOptions(dboptions.nativeHandle_);
+  }
+
+  protected abstract void log(InfoLogLevel infoLogLevel,
+      String logMsg);
+
+  /**
+   * Deletes underlying C++ slice pointer.
+   * Note that this function should be called only after all
+   * RocksDB instances referencing the slice are closed.
+   * Otherwise an undefined behavior will occur.
+   */
+  @Override
+  protected void disposeInternal() {
+    assert(isInitialized());
+    disposeInternal(nativeHandle_);
+  }
+
+  protected native void createNewLoggerOptions(
+      long options);
+  protected native void createNewLoggerDbOptions(
+      long dbOptions);
+  private native void disposeInternal(long handle);
+}

java/src/main/java/org/rocksdb/DBOptions.java

@@ -144,6 +144,13 @@ public class DBOptions extends RocksObject implements DBOptionsInterface {
     return this;
   }
 
+  @Override
+  public DBOptions setLogger(final AbstractLogger logger) {
+    assert(isInitialized());
+    setLogger(nativeHandle_, logger.nativeHandle_);
+    return this;
+  }
+
   @Override
   public DBOptions setInfoLogLevel(
       final InfoLogLevel infoLogLevel) {
@@ -598,6 +605,8 @@ public class DBOptions extends RocksObject implements DBOptionsInterface {
   private native boolean paranoidChecks(long handle);
   private native void setRateLimiter(long handle,
       long rateLimiterHandle);
+  private native void setLogger(long handle,
+      long loggerHandle);
   private native void setInfoLogLevel(long handle, byte logLevel);
   private native byte infoLogLevel(long handle);
   private native void setMaxOpenFiles(long handle, int maxOpenFiles);

java/src/main/java/org/rocksdb/DBOptionsInterface.java

@@ -128,6 +128,19 @@ public interface DBOptionsInterface {
    */
   Object setRateLimiterConfig(RateLimiterConfig config);
 
+  /**
+   * <p>Any internal progress/error information generated by
+   * the db will be written to the Logger if it is non-nullptr,
+   * or to a file stored in the same directory as the DB
+   * contents if info_log is nullptr.</p>
+   *
+   * <p>Default: nullptr</p>
+   *
+   * @param logger {@link AbstractLogger} instance.
+   * @return the instance of the current Object.
+   */
+  Object setLogger(AbstractLogger logger);
+
   /**
    * <p>Sets the RocksDB log level. Default level is INFO</p>
    *

java/src/main/java/org/rocksdb/Options.java

@@ -638,6 +638,13 @@ public class Options extends RocksObject
     return this;
   }
 
+  @Override
+  public Options setLogger(final AbstractLogger logger) {
+    assert(isInitialized());
+    setLogger(nativeHandle_, logger.nativeHandle_);
+    return this;
+  }
+
   @Override
   public Options setInfoLogLevel(final InfoLogLevel infoLogLevel) {
     assert(isInitialized());
@@ -1074,6 +1081,8 @@ public class Options extends RocksObject
   private native boolean paranoidChecks(long handle);
   private native void setRateLimiter(long handle,
       long rateLimiterHandle);
+  private native void setLogger(long handle,
+      long loggerHandle);
   private native void setInfoLogLevel(long handle, byte logLevel);
   private native byte infoLogLevel(long handle);
   private native void setMaxOpenFiles(long handle, int maxOpenFiles);

java/src/test/java/org/rocksdb/AbstractLoggerTest.java

@@ -0,0 +1,140 @@
+package org.rocksdb;
+
+import org.junit.ClassRule;
+import org.junit.Rule;
+import org.junit.Test;
+import org.junit.rules.TemporaryFolder;
+
+import java.util.ArrayList;
+import java.util.List;
+import java.util.concurrent.atomic.AtomicInteger;
+
+import static org.assertj.core.api.Assertions.assertThat;
+
+public class AbstractLoggerTest {
+  @ClassRule
+  public static final RocksMemoryResource rocksMemoryResource =
+      new RocksMemoryResource();
+
+  @Rule
+  public TemporaryFolder dbFolder = new TemporaryFolder();
+
+  private AtomicInteger logMessageCounter = new AtomicInteger();
+
+  @Test
+  public void customLogger() throws RocksDBException {
+    RocksDB db = null;
+    logMessageCounter.set(0);
+    try {
+
+      // Setup options
+      final Options options = new Options().
+          setInfoLogLevel(InfoLogLevel.DEBUG_LEVEL).
+          setCreateIfMissing(true);
+
+      // Create new logger with max log level passed by options
+      AbstractLogger abstractLogger = new AbstractLogger(options) {
+        @Override
+        protected void log(InfoLogLevel infoLogLevel, String logMsg) {
+          assertThat(logMsg).isNotNull();
+          assertThat(logMsg.length()).isGreaterThan(0);
+          logMessageCounter.incrementAndGet();
+        }
+      };
+
+      // Set custom logger to options
+      options.setLogger(abstractLogger);
+
+      db = RocksDB.open(options, dbFolder.getRoot().getAbsolutePath());
+
+      // there should be more than zero received log messages in
+      // debug level.
+      assertThat(logMessageCounter.get()).isGreaterThan(0);
+    } finally {
+      if (db != null) {
+        db.close();
+      }
+    }
+    logMessageCounter.set(0);
+  }
+
+
+  @Test
+  public void fatalLogger() throws RocksDBException {
+    RocksDB db = null;
+    logMessageCounter.set(0);
+
+    try {
+      // Setup options
+      final Options options = new Options().
+          setInfoLogLevel(InfoLogLevel.FATAL_LEVEL).
+          setCreateIfMissing(true);
+
+      // Create new logger with max log level passed by options
+      AbstractLogger abstractLogger = new AbstractLogger(options) {
+        @Override
+        protected void log(InfoLogLevel infoLogLevel, String logMsg) {
+          assertThat(logMsg).isNotNull();
+          assertThat(logMsg.length()).isGreaterThan(0);
+          logMessageCounter.incrementAndGet();
+        }
+      };
+
+      // Set custom logger to options
+      options.setLogger(abstractLogger);
+
+      db = RocksDB.open(options, dbFolder.getRoot().getAbsolutePath());
+
+      // there should be zero messages
+      // using fatal level as log level.
+      assertThat(logMessageCounter.get()).isEqualTo(0);
+    } finally {
+      if (db != null) {
+        db.close();
+      }
+    }
+    logMessageCounter.set(0);
+  }
+
+  @Test
+  public void dbOptionsLogger() throws RocksDBException {
+    RocksDB db = null;
+    List<ColumnFamilyHandle> cfHandles = new ArrayList<>();
+    List<ColumnFamilyDescriptor> cfDescriptors = new ArrayList<>();
+    cfDescriptors.add(new ColumnFamilyDescriptor(RocksDB.DEFAULT_COLUMN_FAMILY));
+
+    logMessageCounter.set(0);
+    try {
+      // Setup options
+      final DBOptions options = new DBOptions().
+          setInfoLogLevel(InfoLogLevel.FATAL_LEVEL).
+          setCreateIfMissing(true);
+
+      // Create new logger with max log level passed by options
+      AbstractLogger abstractLogger = new AbstractLogger(options) {
+        @Override
+        protected void log(InfoLogLevel infoLogLevel, String logMsg) {
+          assertThat(logMsg).isNotNull();
+          assertThat(logMsg.length()).isGreaterThan(0);
+          logMessageCounter.incrementAndGet();
+        }
+      };
+
+      // Set custom logger to options
+      options.setLogger(abstractLogger);
+      db = RocksDB.open(options, dbFolder.getRoot().getAbsolutePath(),
+          cfDescriptors, cfHandles);
+      // there should be zero messages
+      // using fatal level as log level.
+      assertThat(logMessageCounter.get()).isEqualTo(0);
+      logMessageCounter.set(0);
+    } finally {
+      for (ColumnFamilyHandle columnFamilyHandle : cfHandles) {
+        columnFamilyHandle.dispose();
+      }
+      if (db != null) {
+        db.close();
+      }
+    }
+  }
+}