Skip to content

Commit

Permalink
Allow to enable debug logging in quiche (java-native-access#5)
Browse files Browse the repository at this point in the history
Motivation:

During development it is often useful to have debug logging enabled

Modifications:

Allow to use quiche_enable_debug_logging(...) and have it delegate to our InternalLogger

Result:

Fixes netty/netty-incubator-codec-quic#4
  • Loading branch information
normanmaurer authored Nov 10, 2020
1 parent c386b37 commit c9b839e
Show file tree
Hide file tree
Showing 8 changed files with 238 additions and 6 deletions.
6 changes: 6 additions & 0 deletions pom.xml
Original file line number Diff line number Diff line change
Expand Up @@ -512,5 +512,11 @@
<version>${netty.build.version}</version>
<scope>test</scope>
</dependency>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-classic</artifactId>
<version>1.1.7</version>
<scope>test</scope>
</dependency>
</dependencies>
</project>
88 changes: 85 additions & 3 deletions src/main/c/netty_quic_quiche.c
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,12 @@
#define STATICALLY_CLASSNAME "io/netty/incubator/codec/quic/NativeStaticallyReferencedJniMethods"
#define QUICHE_CLASSNAME "io/netty/incubator/codec/quic/Quiche"


static jclass quiche_logger_class;
static jmethodID quiche_logger_class_log;
static jobject quiche_logger;
static JavaVM *global_vm = NULL;

static jint netty_quic_quiche_max_conn_id_len(JNIEnv* env, jclass clazz) {
return QUICHE_MAX_CONN_ID_LEN;
}
Expand Down Expand Up @@ -346,6 +352,34 @@ static void netty_quic_quiche_config_free(JNIEnv* env, jclass clazz, jlong confi
quiche_config_free((quiche_config*) config);
}

static void log_to_java(const char *line, void *argp) {
JNIEnv* env = NULL;
if (global_vm == NULL || line == NULL) {
return;
}
if ((*global_vm)->GetEnv(global_vm, (void **) &env, NETTY_JNI_UTIL_JNI_VERSION) != JNI_OK) {
return;
}

jstring message = (*env)->NewStringUTF(env, line);
if (message == NULL) {
// out of memory.
return;
}
(*env)->CallVoidMethod(env, quiche_logger, quiche_logger_class_log, message);
}

static void netty_quic_quiche_enable_debug_logging(JNIEnv* env, jclass clazz, jobject logger) {
if (quiche_logger != NULL) {
return;
}
if ((quiche_logger = (*env)->NewGlobalRef(env, logger)) == NULL) {
return;
}

quiche_enable_debug_logging(log_to_java, NULL);
}

// JNI Registered Methods End

// JNI Method Registration Table Begin
Expand Down Expand Up @@ -424,12 +458,40 @@ static const JNINativeMethod fixed_method_table[] = {

static const jint fixed_method_table_size = sizeof(fixed_method_table) / sizeof(fixed_method_table[0]);

static jint dynamicMethodsTableSize() {
return fixed_method_table_size + 1;
}

static JNINativeMethod* createDynamicMethodsTable(const char* packagePrefix) {
char* dynamicTypeName = NULL;
int len = sizeof(JNINativeMethod) * dynamicMethodsTableSize();
JNINativeMethod* dynamicMethods = malloc(len);
if (dynamicMethods == NULL) {
goto error;
}
memset(dynamicMethods, 0, len);
memcpy(dynamicMethods, fixed_method_table, sizeof(fixed_method_table));

JNINativeMethod* dynamicMethod = &dynamicMethods[fixed_method_table_size];
NETTY_JNI_UTIL_PREPEND(packagePrefix, "io/netty/incubator/codec/quic/QuicheLogger;)V", dynamicTypeName, error);
NETTY_JNI_UTIL_PREPEND("(L", dynamicTypeName, dynamicMethod->signature, error);
netty_jni_util_free_dynamic_name(&dynamicTypeName);
dynamicMethod->name = "quiche_enable_debug_logging";
dynamicMethod->fnPtr = (void *) netty_quic_quiche_enable_debug_logging;
return dynamicMethods;
error:
netty_jni_util_free_dynamic_methods_table(dynamicMethods, fixed_method_table_size, dynamicMethodsTableSize());
free(dynamicTypeName);
return NULL;
}

// JNI Method Registration Table End

static jint netty_quic_quiche_JNI_OnLoad(JNIEnv* env, const char* packagePrefix) {
int ret = JNI_ERR;
int staticallyRegistered = 0;
int nativeRegistered = 0;
char* name = NULL;

// We must register the statically referenced methods first!
if (netty_jni_util_register_natives(env,
Expand All @@ -441,34 +503,50 @@ static jint netty_quic_quiche_JNI_OnLoad(JNIEnv* env, const char* packagePrefix)
}
staticallyRegistered = 1;

JNINativeMethod* dynamicMethods = createDynamicMethodsTable(packagePrefix);
if (dynamicMethods == NULL) {
goto done;
}
if (netty_jni_util_register_natives(env,
packagePrefix,
QUICHE_CLASSNAME,
fixed_method_table,
fixed_method_table_size) != 0) {
dynamicMethods,
dynamicMethodsTableSize()) != 0) {
goto done;
}
nativeRegistered = 1;

NETTY_JNI_UTIL_PREPEND(packagePrefix, "io/netty/incubator/codec/quic/QuicheLogger", name, done);
NETTY_JNI_UTIL_LOAD_CLASS(env, quiche_logger_class, name, done);
NETTY_JNI_UTIL_GET_METHOD(env, quiche_logger_class, quiche_logger_class_log, "log", "(Ljava/lang/String;)V", done);
// Initialize this module

ret = NETTY_JNI_UTIL_JNI_VERSION;
done:

if (ret == JNI_ERR) {
if (staticallyRegistered == 1) {
netty_jni_util_unregister_natives(env, packagePrefix, STATICALLY_CLASSNAME);
}
if (nativeRegistered == 1) {
netty_jni_util_unregister_natives(env, packagePrefix, QUICHE_CLASSNAME);
}

NETTY_JNI_UTIL_UNLOAD_CLASS(env, quiche_logger_class);
netty_jni_util_free_dynamic_methods_table(dynamicMethods, fixed_method_table_size, dynamicMethodsTableSize());
}
return ret;
}

static void netty_quic_quiche_JNI_OnUnload(JNIEnv* env, const char* packagePrefix) {
NETTY_JNI_UTIL_UNLOAD_CLASS(env, quiche_logger_class);

netty_jni_util_unregister_natives(env, packagePrefix, STATICALLY_CLASSNAME);
netty_jni_util_unregister_natives(env, packagePrefix, QUICHE_CLASSNAME);

if (quiche_logger != NULL) {
(*env)->DeleteGlobalRef(env, quiche_logger);
quiche_logger = NULL;
}
}

// Invoked by the JVM when statically linked
Expand All @@ -478,20 +556,24 @@ static void netty_quic_quiche_JNI_OnUnload(JNIEnv* env, const char* packagePrefi

// Invoked by the JVM when statically linked
JNIEXPORT jint JNI_OnLoad_netty_quic_quiche(JavaVM* vm, void* reserved) {
global_vm = vm;
return netty_jni_util_JNI_OnLoad(vm, reserved, "netty_quic_quiche", netty_quic_quiche_JNI_OnLoad);
}

// Invoked by the JVM when statically linked
JNIEXPORT void JNI_OnUnload_netty_quic_quiche_JNI_OnLoad(JavaVM* vm, void* reserved) {
netty_jni_util_JNI_OnUnload(vm, reserved, netty_quic_quiche_JNI_OnUnload);
global_vm = NULL;
}

#ifndef NETTY_BUILD_STATIC
JNIEXPORT jint JNI_OnLoad(JavaVM* vm, void* reserved) {
global_vm = vm;
return netty_jni_util_JNI_OnLoad(vm, reserved, "netty_quic_quiche", netty_quic_quiche_JNI_OnLoad);
}

JNIEXPORT void JNI_OnUnload(JavaVM* vm, void* reserved) {
netty_jni_util_JNI_OnUnload(vm, reserved, netty_quic_quiche_JNI_OnUnload);
global_vm = NULL;
}
#endif /* NETTY_BUILD_STATIC */
7 changes: 6 additions & 1 deletion src/main/java/io/netty/incubator/codec/quic/QuicCodec.java
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@
package io.netty.incubator.codec.quic;

import io.netty.buffer.ByteBuf;
import io.netty.buffer.ByteBufUtil;
import io.netty.buffer.Unpooled;
import io.netty.channel.ChannelDuplexHandler;
import io.netty.channel.ChannelHandler;
Expand Down Expand Up @@ -221,7 +222,11 @@ private void quicPacketRead(ChannelHandlerContext ctx, DatagramPacket packet, by
LOGGER.debug("quiche_accept failed");
return;
}
channel = new QuicheQuicChannel(this, ctx.channel(), conn, true, packet.sender(), quicChannelHandler);

String traceId = Quiche.traceId(conn, dcid);
channel = new QuicheQuicChannel(this, ctx.channel(), conn, traceId,
true, packet.sender(), quicChannelHandler);

connections.put(connId, channel);
ctx.channel().eventLoop().register(channel);
}
Expand Down
20 changes: 20 additions & 0 deletions src/main/java/io/netty/incubator/codec/quic/Quiche.java
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,8 @@
*/
package io.netty.incubator.codec.quic;

import io.netty.buffer.ByteBuf;
import io.netty.buffer.ByteBufUtil;
import io.netty.channel.ChannelPromise;
import io.netty.util.collection.IntObjectHashMap;
import io.netty.util.collection.IntObjectMap;
Expand All @@ -31,6 +33,7 @@
final class Quiche {
private static final InternalLogger logger = InternalLoggerFactory.getInstance(Quiche.class);
private static final IntObjectMap<String> ERROR_MAP = new IntObjectHashMap<>();
private static final boolean DEBUG_LOGGING_ENABLED = logger.isDebugEnabled();

static {
try {
Expand All @@ -41,6 +44,11 @@ final class Quiche {
// The library was not previously loaded, load it now.
loadNativeLibrary();
}

// Let's enable debug logging for quiche if its enabled in our logger.
if (DEBUG_LOGGING_ENABLED) {
quiche_enable_debug_logging(new QuicheLogger(logger));
}
}

private static void loadNativeLibrary() {
Expand Down Expand Up @@ -348,6 +356,12 @@ static native int quiche_retry(long scidAddr, int scidLen, long dcidAddr, int dc
static native void quiche_config_enable_hystart(long configAddr, boolean value);
static native void quiche_config_free(long configAddr);

/**
* See
* <a href="https://github.com/cloudflare/quiche/blob/0.6.0/include/quiche.h#L108">quiche_config_new</a>.
*/
private static native void quiche_enable_debug_logging(QuicheLogger logger);

static {
ERROR_MAP.put(QUICHE_ERR_DONE, "QUICHE_ERR_DONE");
ERROR_MAP.put(QUICHE_ERR_BUFFER_TOO_SHORT, "QUICHE_ERR_BUFFER_TOO_SHORT");
Expand Down Expand Up @@ -398,5 +412,11 @@ static void notifyPromise(int res, ChannelPromise promise) {
}
}

static String traceId(long connAddr, ByteBuf buffer) {
// We just do the same as quiche does for the traceid but we should use Connection:trace_id() once it is exposed
// in the c API.
return ByteBufUtil.hexDump(buffer);
}

private Quiche() { }
}
34 changes: 34 additions & 0 deletions src/main/java/io/netty/incubator/codec/quic/QuicheLogger.java
Original file line number Diff line number Diff line change
@@ -0,0 +1,34 @@
/*
* Copyright 2020 The Netty Project
*
* The Netty Project 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:
*
* https://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.netty.incubator.codec.quic;

import io.netty.util.internal.logging.InternalLogger;

/**
* Delegates QUICHE logging to {@link InternalLogger}.
*/
final class QuicheLogger {
private final InternalLogger logger;

QuicheLogger(InternalLogger logger) {
this.logger = logger;
}

// Called from JNI.
void log(String msg) {
logger.debug(msg);
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -49,6 +49,7 @@ final class QuicheQuicChannel extends AbstractChannel implements QuicChannel {
private final ChannelConfig config;
private final boolean server;
private final QuicCodec codec;

private final ChannelFutureListener flushListener = new ChannelFutureListener() {
@Override
public void operationComplete(ChannelFuture channelFuture) {
Expand Down Expand Up @@ -85,9 +86,9 @@ public void run() {

private volatile boolean active = true;

QuicheQuicChannel(QuicCodec codec, Channel parent, long connAddr, boolean server,
QuicheQuicChannel(QuicCodec codec, Channel parent, long connAddr, String traceId, boolean server,
InetSocketAddress remote, ChannelHandler handler) {
super(parent);
super(parent, new QuicheQuicChannelId(traceId));
this.codec = codec;
config = new DefaultChannelConfig(this);
this.server = server;
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,57 @@
/*
* Copyright 2020 The Netty Project
*
* The Netty Project 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:
*
* https://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.netty.incubator.codec.quic;

import io.netty.channel.ChannelId;

final class QuicheQuicChannelId implements ChannelId {

private final String id;

QuicheQuicChannelId(String id) {
this.id = id;
}

@Override
public String asShortText() {
return id;
}

@Override
public String asLongText() {
return id;
}

@Override
public int compareTo(ChannelId o) {
return id.compareTo(o.asLongText());
}

@Override
public int hashCode() {
return id.hashCode();
}

@Override
public boolean equals(Object obj) {
return id.equals(obj);
}

@Override
public String toString() {
return id;
}
}
27 changes: 27 additions & 0 deletions src/test/resources/logback-test.xml
Original file line number Diff line number Diff line change
@@ -0,0 +1,27 @@
<?xml version="1.0" encoding="UTF-8"?>
<!--
~ Copyright 2020 The Netty Project
~
~ The Netty Project 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:
~
~ https://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.
-->
<configuration debug="false">
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
</appender>

<root level="${logLevel:-debug}">
<appender-ref ref="STDOUT" />
</root>
</configuration>

0 comments on commit c9b839e

Please sign in to comment.