Contain JNI logging failures and preserve UTF-8 payloads

This commit is contained in:
evgeny committed 2026-10-28 12:28:28 +01:00
1 parent c656e3a96b
commit a77fc553e7
3 files changed
+139 -27

No files matched your search

@@ -69,9 +69,12 @@ object LogManager {
return history.getRecent(count)
}
/** JNI передаёт bridge-уровни 0=TRACE..4=ERROR; DEBUG_* преобразуются и фильтруются в C, собственные bridge-логи могут обходить фильтр.
/** JNI передаёт обычный UTF-8 в byte[], не Modified UTF-8 NewStringUTF: emoji сохраняются, повреждённые байты дают U+FFFD.
* Уровни bridge: 0=TRACE..4=ERROR; DEBUG_* фильтруются в C, собственные bridge-логи могут обходить фильтр.
* Неизвестный уровень записывается предупреждением с исходным значением; null category/message заменяются пустыми строками. */
fun onNativeLog(level: Int, category: String?, message: String?) {
fun onNativeLog(level: Int, category: ByteArray?, message: ByteArray?) {
val categoryText = category?.toString(Charsets.UTF_8).orEmpty()
val messageText = message?.toString(Charsets.UTF_8).orEmpty()
val lvl = when (level) {
0 -> "TRACE"
1 -> "DEBUG"
@@ -79,10 +82,10 @@ object LogManager {
3 -> "WARN"
4 -> "ERROR"
else -> {
addLog("WARN", "Log", "Unknown JNI log level=$level category=${category.orEmpty()} message=${message.orEmpty()}")
addLog("WARN", "Log", "Unknown JNI log level=$level category=$categoryText message=$messageText")
return
}
}
addLog(lvl, category ?: "", message ?: "")
addLog(lvl, categoryText, messageText)
}
}
@@ -0,0 +1,20 @@
package com.utun.chat.data
import java.io.File
import org.junit.Assert.*
import org.junit.Test
/** Сопоставляет настоящий JNI lookup с JVM-дескриптором скомпилированного Kotlin callback. */
class NativeLogContractTest {
@Test fun nativeLookupMatchesTheCompiledKotlinByteArrayCallback() {
val method = LogManager::class.java.declaredMethods.single { it.name == "onNativeLog" }
val descriptor = "(" + method.parameterTypes.joinToString("") {
if (it == Int::class.javaPrimitiveType) "I" else it.name.replace('.', '/')
} + ")" + if (method.returnType == Void.TYPE) "V" else method.returnType.name
val source = File(requireNotNull(System.getProperty("utun.androidBridgeSource"))).readText()
val native = Regex("GetMethodID\\(env, cls, \\\"onNativeLog\\\", \\\"([^\\\"]+)\\\"\\)").find(source)
assertNotNull("JNI onNativeLog lookup missing", native)
assertEquals("(I[B[B)V", descriptor)
assertEquals(descriptor, native!!.groupValues[1])
}
}
@@ -58,6 +58,7 @@
#ifdef __ANDROID__
#include <jni.h>
#include <android/log.h>
#include <pthread.h>
#define LOG_TAG "utun-bridge"
#else
#define ANDROID_LOG_VERBOSE 2
@@ -97,7 +98,8 @@ static void bridge_log(int level, const char* fmt, ...) {
fprintf(stderr, "%s\n", fmt_buf);
#endif
if (g_on_log) g_on_log(level, "JNI", fmt_buf);
utun_log_fn on_log = __atomic_load_n(&g_on_log, __ATOMIC_ACQUIRE);
if (on_log) on_log(level, "JNI", fmt_buf);
}
static void bridge_debug_hook(int level, const char* category, const char* message) {
@@ -111,7 +113,8 @@ static void bridge_debug_hook(int level, const char* category, const char* messa
#endif
udp_log_write(message, (int)strlen(message));
if (level == DEBUG_LEVEL_ERROR) udp_log_flush();
if (g_on_log) g_on_log(bridge_level, category, message);
utun_log_fn on_log = __atomic_load_n(&g_on_log, __ATOMIC_ACQUIRE);
if (on_log) on_log(bridge_level, category, message);
}
static utun_config_string_fn g_cfg_string = NULL;
@@ -134,7 +137,8 @@ static int cfg_wrapper_int(const char* key, int def) {
/* ── Public API ── */
void utun_bridge_log(int level, const char* category, const char* message) {
if (g_on_log) g_on_log(level, category, message);
utun_log_fn on_log = __atomic_load_n(&g_on_log, __ATOMIC_ACQUIRE);
if (on_log) on_log(level, category, message);
}
void utun_bridge_event(int event_type, const char* json_data) {
@@ -145,7 +149,7 @@ bool utun_bridge_init(const char* db_path, int control_port,
utun_log_fn on_log,
utun_event_fn on_event,
const struct utun_bridge_config* config) {
g_on_log = on_log;
__atomic_store_n(&g_on_log, on_log, __ATOMIC_RELEASE);
g_on_event = on_event;
debug_set_log_hook(bridge_debug_hook);
@@ -170,7 +174,7 @@ int utun_bridge_destroy(void) {
if (instance_lite_stop()) { bridge_log(BLEV_ERROR, "bridge destroy refused: worker is not joined"); return -1; }
voice_recorder_deinit();
utun_config_set_provider(NULL);
g_on_log = NULL;
__atomic_store_n(&g_on_log, NULL, __ATOMIC_RELEASE);
g_cfg_string = NULL;
g_cfg_int64 = NULL;
g_cfg_int = NULL;
@@ -1758,6 +1762,8 @@ static jobject g_config_callback = NULL;
static jmethodID g_radio_config_mid = NULL; /* Публикуется в init, очищается только после join. */
static int g_radio_config_available; /* Producer читает только atomic-флаг, не JNI global ref. */
static jobject g_log_callback = NULL;
static pthread_mutex_t g_log_callback_lock = PTHREAD_MUTEX_INITIALIZER; /* Замена global ref / получение своего local ref. */
static __thread int g_log_callback_active; /* Callback не может рекурсивно пересылать native-лог того же потока. */
static jobject g_event_callback = NULL;
static jmethodID g_event_mid = NULL;
@@ -1767,28 +1773,92 @@ JNIEXPORT jint JNICALL JNI_OnLoad(JavaVM* vm, void* reserved) {
return JNI_VERSION_1_6;
}
/* ── JNI log callback → LogManager.onNativeLog() ── */
/* JNI log callback: удерживает свой local ref, передаёт обычный UTF-8 как byte[], освобождает все ссылки.
* Ошибки идут прямо в logcat: bridge_log/DEBUG_* снова вызвали бы сломанный callback.
* Свои Java-исключения описываем/снимаем; уже существующее исключение вызывающего JNI-кода сохраняем. */
static void jni_on_log(int level, const char* category, const char* message) {
if (!g_jvm || !g_log_callback || !category || !message) return;
if (g_log_callback_active) {
__android_log_print(ANDROID_LOG_ERROR, LOG_TAG, "JNI log: recursive callback suppressed level=%d", level); return;
}
if (!g_jvm || !category || !message) {
__android_log_print(ANDROID_LOG_ERROR, LOG_TAG, "JNI log: invalid input vm=%p category=%p message=%p level=%d",
(void*)g_jvm, (const void*)category, (const void*)message, level); return;
}
g_log_callback_active = 1;
JNIEnv* env = NULL;
int attached = 0;
jobject callback = NULL;
jclass cls = NULL;
jbyteArray values[2] = {NULL, NULL};
const char* text[2] = {category, message};
const char* fields[2] = {"category", "message"};
jint res = (*g_jvm)->GetEnv(g_jvm, (void**)&env, JNI_VERSION_1_6);
if (res == JNI_EDETACHED) {
if ((*g_jvm)->AttachCurrentThread(g_jvm, &env, NULL) != JNI_OK) return;
res = (*g_jvm)->AttachCurrentThread(g_jvm, (void*)&env, NULL);
if (res != JNI_OK) {
__android_log_print(ANDROID_LOG_ERROR, LOG_TAG, "JNI log: AttachCurrentThread failed rc=%d level=%d", res, level);
goto finish;
}
attached = 1;
} else if (res != JNI_OK) {
return;
__android_log_print(ANDROID_LOG_ERROR, LOG_TAG, "JNI log: GetEnv failed rc=%d level=%d", res, level); goto finish;
}
jclass cls = (*env)->GetObjectClass(env, g_log_callback);
jmethodID mid = (*env)->GetMethodID(env, cls, "onNativeLog", "(ILjava/lang/String;Ljava/lang/String;)V");
if (!mid) { if (attached) (*g_jvm)->DetachCurrentThread(g_jvm); return; }
jstring jcat = (*env)->NewStringUTF(env, category);
jstring jmsg = (*env)->NewStringUTF(env, message);
(*env)->CallVoidMethod(env, g_log_callback, mid, level, jcat, jmsg);
(*env)->DeleteLocalRef(env, jmsg);
(*env)->DeleteLocalRef(env, jcat);
if (attached) (*g_jvm)->DetachCurrentThread(g_jvm);
if ((*env)->ExceptionCheck(env)) {
__android_log_print(ANDROID_LOG_ERROR, LOG_TAG, "JNI log: preserving preexisting Java exception level=%d", level);
goto finish;
}
pthread_mutex_lock(&g_log_callback_lock);
int configured = g_log_callback != NULL;
if (configured) callback = (*env)->NewLocalRef(env, g_log_callback);
pthread_mutex_unlock(&g_log_callback_lock);
if (!configured) goto finish;
if (!callback) {
__android_log_print(ANDROID_LOG_ERROR, LOG_TAG, "JNI log: NewLocalRef failed level=%d", level); goto cleanup;
}
cls = (*env)->GetObjectClass(env, callback);
if (!cls) {
__android_log_print(ANDROID_LOG_ERROR, LOG_TAG, "JNI log: GetObjectClass failed level=%d", level); goto cleanup;
}
jmethodID mid = (*env)->GetMethodID(env, cls, "onNativeLog", "(I[B[B)V");
if (!mid) {
__android_log_print(ANDROID_LOG_ERROR, LOG_TAG, "JNI log: GetMethodID onNativeLog(I[B[B)V failed level=%d", level);
goto cleanup;
}
for (unsigned i = 0; i < 2; i++) {
size_t length = strlen(text[i]);
if (length > INT_MAX) {
__android_log_print(ANDROID_LOG_ERROR, LOG_TAG, "JNI log: %s too long bytes=%zu level=%d", fields[i], length, level);
goto cleanup;
}
values[i] = (*env)->NewByteArray(env, (jsize)length);
if (!values[i]) {
__android_log_print(ANDROID_LOG_ERROR, LOG_TAG, "JNI log: NewByteArray %s failed bytes=%zu level=%d", fields[i], length, level);
goto cleanup;
}
if (length) (*env)->SetByteArrayRegion(env, values[i], 0, (jsize)length, (const jbyte*)text[i]);
if ((*env)->ExceptionCheck(env)) {
__android_log_print(ANDROID_LOG_ERROR, LOG_TAG, "JNI log: SetByteArrayRegion %s failed bytes=%zu level=%d",
fields[i], length, level); goto cleanup;
}
}
(*env)->CallVoidMethod(env, callback, mid, (jint)level, values[0], values[1]);
if ((*env)->ExceptionCheck(env)) {
__android_log_print(ANDROID_LOG_ERROR, LOG_TAG, "JNI log: onNativeLog threw level=%d", level);
}
cleanup:
if ((*env)->ExceptionCheck(env)) { (*env)->ExceptionDescribe(env); (*env)->ExceptionClear(env); }
for (unsigned i = 0; i < 2; i++) if (values[i]) (*env)->DeleteLocalRef(env, values[i]);
if (cls) (*env)->DeleteLocalRef(env, cls);
if (callback) (*env)->DeleteLocalRef(env, callback);
finish:
if (attached) {
res = (*g_jvm)->DetachCurrentThread(g_jvm);
if (res != JNI_OK) {
__android_log_print(ANDROID_LOG_ERROR, LOG_TAG, "JNI log: DetachCurrentThread failed rc=%d level=%d", res, level);
}
}
g_log_callback_active = 0;
}
/* ── JNI event callback (chat_event → Kotlin) ── */
@@ -1913,13 +1983,24 @@ JNIEXPORT jboolean JNICALL Java_com_utun_chat_data_NativeLib_nativeInit(
}
__atomic_store_n(&g_radio_config_available, g_radio_config_mid != NULL, __ATOMIC_RELEASE);
if (g_log_callback) (*env)->DeleteGlobalRef(env, g_log_callback);
g_log_callback = logCb ? (*env)->NewGlobalRef(env, logCb) : NULL;
if ((*env)->ExceptionCheck(env)) {
__android_log_print(ANDROID_LOG_ERROR, LOG_TAG, "JNI log: nativeInit has pending config exception"); return JNI_FALSE;
}
jobject next_log_callback = logCb ? (*env)->NewGlobalRef(env, logCb) : NULL;
if (logCb && !next_log_callback) {
__android_log_print(ANDROID_LOG_ERROR, LOG_TAG, "JNI log: nativeInit NewGlobalRef failed"); return JNI_FALSE;
}
pthread_mutex_lock(&g_log_callback_lock);
jobject previous_log_callback = g_log_callback;
g_log_callback = next_log_callback;
pthread_mutex_unlock(&g_log_callback_lock);
if (previous_log_callback) (*env)->DeleteGlobalRef(env, previous_log_callback);
__android_log_print(ANDROID_LOG_INFO, LOG_TAG, "JNI log callback configured=%d; UTF-8 byte arrays", logCb != NULL);
const char* db = dbPath ? (*env)->GetStringUTFChars(env, dbPath, NULL) : NULL;
if (db) { strncpy(g_db_path, db, sizeof(g_db_path) - 1); g_db_path[sizeof(g_db_path) - 1] = '\0'; }
utun_log_fn log_cb = g_log_callback ? jni_on_log : NULL;
utun_log_fn log_cb = logCb ? jni_on_log : NULL;
struct utun_bridge_config cfg = {
.get_string = jni_cfg_get_string,
@@ -2087,7 +2168,11 @@ JNIEXPORT jboolean JNICALL Java_com_utun_chat_data_NativeLib_nativeDestroy(
__atomic_store_n(&g_radio_config_available, 0, __ATOMIC_RELEASE);
g_radio_config_mid = NULL;
if (g_config_callback) { (*env)->DeleteGlobalRef(env, g_config_callback); g_config_callback = NULL; }
if (g_log_callback) { (*env)->DeleteGlobalRef(env, g_log_callback); g_log_callback = NULL; }
pthread_mutex_lock(&g_log_callback_lock);
jobject previous_log_callback = g_log_callback;
g_log_callback = NULL;
pthread_mutex_unlock(&g_log_callback_lock);
if (previous_log_callback) (*env)->DeleteGlobalRef(env, previous_log_callback);
if (g_event_callback) { (*env)->DeleteGlobalRef(env, g_event_callback); g_event_callback = NULL; }
return JNI_TRUE;
}
@@ -2488,7 +2573,11 @@ JNIEXPORT void JNICALL Java_com_utun_chat_data_NativeLib_nativeSetSoundOnMessage
JNIEXPORT void JNICALL Java_com_utun_chat_data_NativeLib_nativeSubscribeLogs(
JNIEnv* env, jobject thiz, jboolean enabled) {
(void)thiz; (void)env;
g_on_log = (enabled && g_log_callback) ? jni_on_log : NULL;
pthread_mutex_lock(&g_log_callback_lock);
int configured = g_log_callback != NULL;
__atomic_store_n(&g_on_log, enabled && configured ? jni_on_log : NULL, __ATOMIC_RELEASE);
pthread_mutex_unlock(&g_log_callback_lock);
__android_log_print(ANDROID_LOG_INFO, LOG_TAG, "JNI log forwarding enabled=%d callback=%d", enabled != JNI_FALSE, configured);
}
JNIEXPORT void JNICALL Java_com_utun_chat_data_NativeLib_nativeSetUdpLogTarget(