From a77fc553e7127a44e13656b9646d55ca0fb89b8d Mon Sep 17 00:00:00 2001 From: evgeny Date: Wed, 28 Oct 2026 11:58:11 +0100 Subject: [PATCH] Contain JNI logging failures and preserve UTF-8 payloads --- .../java/com/utun/chat/data/LogManager.kt | 11 +- .../utun/chat/data/NativeLogContractTest.kt | 20 +++ .../jni_bridge/android_jni_bridge.c | 135 +++++++++++++++--- 3 files changed, 139 insertions(+), 27 deletions(-) create mode 100644 tools/chatgui-android/app/src/test/java/com/utun/chat/data/NativeLogContractTest.kt diff --git a/tools/chatgui-android/app/src/main/java/com/utun/chat/data/LogManager.kt b/tools/chatgui-android/app/src/main/java/com/utun/chat/data/LogManager.kt index 210bced5..019e98e5 100644 --- a/tools/chatgui-android/app/src/main/java/com/utun/chat/data/LogManager.kt +++ b/tools/chatgui-android/app/src/main/java/com/utun/chat/data/LogManager.kt @@ -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) } } diff --git a/tools/chatgui-android/app/src/test/java/com/utun/chat/data/NativeLogContractTest.kt b/tools/chatgui-android/app/src/test/java/com/utun/chat/data/NativeLogContractTest.kt new file mode 100644 index 00000000..0d0ddf48 --- /dev/null +++ b/tools/chatgui-android/app/src/test/java/com/utun/chat/data/NativeLogContractTest.kt @@ -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]) + } +} diff --git a/tools/chatgui-android/jni_bridge/android_jni_bridge.c b/tools/chatgui-android/jni_bridge/android_jni_bridge.c index d5a2fa3d..4c7bf206 100644 --- a/tools/chatgui-android/jni_bridge/android_jni_bridge.c +++ b/tools/chatgui-android/jni_bridge/android_jni_bridge.c @@ -58,6 +58,7 @@ #ifdef __ANDROID__ #include #include +#include #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(