From a3bd4142f2074ecac4856ece3105092cbe4e9da1 Mon Sep 17 00:00:00 2001 From: fyrz Date: Tue, 10 Feb 2015 21:59:40 +0100 Subject: [PATCH] [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 | 4 +- java/rocksjni/loggerjnicallback.cc | 167 ++++++++++++++++++ java/rocksjni/loggerjnicallback.h | 40 +++++ java/rocksjni/options.cc | 26 +++ java/rocksjni/portal.h | 67 +++++++ .../main/java/org/rocksdb/AbstractLogger.java | 60 +++++++ java/src/main/java/org/rocksdb/DBOptions.java | 9 + .../java/org/rocksdb/DBOptionsInterface.java | 13 ++ java/src/main/java/org/rocksdb/Options.java | 9 + .../java/org/rocksdb/AbstractLoggerTest.java | 140 +++++++++++++++ 10 files changed, 534 insertions(+), 1 deletion(-) create mode 100644 java/rocksjni/loggerjnicallback.cc create mode 100644 java/rocksjni/loggerjnicallback.h create mode 100644 java/src/main/java/org/rocksdb/AbstractLogger.java create mode 100644 java/src/test/java/org/rocksdb/AbstractLoggerTest.java diff --git a/java/Makefile b/java/Makefile index 26a8b5a92..2530af9bd 100644 --- a/java/Makefile +++ b/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\ diff --git a/java/rocksjni/loggerjnicallback.cc b/java/rocksjni/loggerjnicallback.cc new file mode 100644 index 000000000..170be6396 --- /dev/null +++ b/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(&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 + (joptions)->info_log_level); + std::shared_ptr *pLoggerJniCallback = + new std::shared_ptr; + *pLoggerJniCallback = std::shared_ptr(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 + (jdb_options)->info_log_level); + std::shared_ptr *pLoggerJniCallback = + new std::shared_ptr; + *pLoggerJniCallback = std::shared_ptr(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 *handle = + reinterpret_cast *>(jhandle); + handle->reset(); +} diff --git a/java/rocksjni/loggerjnicallback.h b/java/rocksjni/loggerjnicallback.h new file mode 100644 index 000000000..23bf2ba23 --- /dev/null +++ b/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 +#include +#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 diff --git a/java/rocksjni/options.cc b/java/rocksjni/options.cc index 9f0875b32..277b040d3 100644 --- a/java/rocksjni/options.cc +++ b/java/rocksjni/options.cc @@ -639,6 +639,19 @@ void Java_org_rocksdb_Options_setRateLimiter( reinterpret_cast(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 *pLogger = + reinterpret_cast *>( + jlogger_handle); + reinterpret_cast(jhandle)->info_log = *pLogger; +} + /* * Class: org_rocksdb_Options * Method: setInfoLogLevel @@ -2935,6 +2948,19 @@ void Java_org_rocksdb_DBOptions_setRateLimiter( reinterpret_cast(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 *pLogger = + reinterpret_cast *>( + jlogger_handle); + reinterpret_cast(jhandle)->info_log = *pLogger; +} + /* * Class: org_rocksdb_DBOptions * Method: setInfoLogLevel diff --git a/java/rocksjni/portal.h b/java/rocksjni/portal.h index 0c35eef4e..194d259fb 100644 --- a/java/rocksjni/portal.h +++ b/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*, 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: /* diff --git a/java/src/main/java/org/rocksdb/AbstractLogger.java b/java/src/main/java/org/rocksdb/AbstractLogger.java new file mode 100644 index 000000000..e7a40f324 --- /dev/null +++ b/java/src/main/java/org/rocksdb/AbstractLogger.java @@ -0,0 +1,60 @@ +package org.rocksdb; + +/** + *

This class provides a custom logger functionality + * in Java which wraps {@code RocksDB} logging facilities. + *

+ * + *

Using this class RocksDB can log with common + * Java logging APIs like Log4j or Slf4j without keeping + * database logs in the filesystem.

+ */ +public abstract class AbstractLogger extends RocksObject { + + /** + *

AbstractLogger constructor.

+ * + *

Important: the log level set within + * the {@link org.rocksdb.Options} instance will be used as + * maximum log level of RocksDB.

+ * + * @param options {@link org.rocksdb.Options} instance. + */ + public AbstractLogger(Options options) { + createNewLoggerOptions(options.nativeHandle_); + } + + /** + *

AbstractLogger constructor.

+ * + *

Important: the log level set within + * the {@link org.rocksdb.DBOptions} instance will be used + * as maximum log level of RocksDB.

+ * + * @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); +} diff --git a/java/src/main/java/org/rocksdb/DBOptions.java b/java/src/main/java/org/rocksdb/DBOptions.java index 4e2d5426c..048e7ffbd 100644 --- a/java/src/main/java/org/rocksdb/DBOptions.java +++ b/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); diff --git a/java/src/main/java/org/rocksdb/DBOptionsInterface.java b/java/src/main/java/org/rocksdb/DBOptionsInterface.java index 38c0338e4..e042baecf 100644 --- a/java/src/main/java/org/rocksdb/DBOptionsInterface.java +++ b/java/src/main/java/org/rocksdb/DBOptionsInterface.java @@ -128,6 +128,19 @@ public interface DBOptionsInterface { */ Object setRateLimiterConfig(RateLimiterConfig config); + /** + *

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.

+ * + *

Default: nullptr

+ * + * @param logger {@link AbstractLogger} instance. + * @return the instance of the current Object. + */ + Object setLogger(AbstractLogger logger); + /** *

Sets the RocksDB log level. Default level is INFO

* diff --git a/java/src/main/java/org/rocksdb/Options.java b/java/src/main/java/org/rocksdb/Options.java index 98e6b19c6..8d946e5a5 100644 --- a/java/src/main/java/org/rocksdb/Options.java +++ b/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); diff --git a/java/src/test/java/org/rocksdb/AbstractLoggerTest.java b/java/src/test/java/org/rocksdb/AbstractLoggerTest.java new file mode 100644 index 000000000..64062f1a9 --- /dev/null +++ b/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 cfHandles = new ArrayList<>(); + List 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(); + } + } + } +}