From 23edda0659918ca0b5b67859f2efa040108889d1 Mon Sep 17 00:00:00 2001 From: Tienson Qin Date: Thu, 24 Sep 2026 23:54:00 +0000 Subject: [PATCH] ffi+drain: route OCaml diagnostics to logcat and trace apply call sites MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit fprintf(stderr) never reaches logcat on Android (zygote redirects stdio), so the previous exception logging was invisible there — switch to __android_log_print under __ANDROID__. The drain's empty-patch trace showed the create-graph resolution never produced an empty patch and Dart went silent after 'finish id=2' — so applySnapshot either blocked inside the FFI call or hung in the backend apply. Add entry/exit debugPrints around the three drain producers' FFI calls and before/after drain applyPatch, so the next run names the hang. --- flutter/lib/logseq_chat_native_bridge.dart | 29 +++++++++++++++-- flutter/lib/native_effect_drain.dart | 2 ++ shared/native/logseq_chat_core_ffi.c | 38 ++++++++++++++-------- 3 files changed, 52 insertions(+), 17 deletions(-) diff --git a/flutter/lib/logseq_chat_native_bridge.dart b/flutter/lib/logseq_chat_native_bridge.dart index 7c6cb2e8..063aae7e 100644 --- a/flutter/lib/logseq_chat_native_bridge.dart +++ b/flutter/lib/logseq_chat_native_bridge.dart @@ -2,6 +2,7 @@ import 'dart:ffi'; import 'dart:isolate'; import 'package:ffi/ffi.dart'; +import 'package:flutter/foundation.dart'; import 'lui_dispatch.dart'; import 'native_effect_drain.dart'; @@ -228,6 +229,7 @@ final class LogseqChatNativeBridge required String message, }) { if (_runtimeScheduler.isCoreBusy) { + debugPrint('[NativeBridge] resolveEffect id=$id queued (core busy)'); _runtimeScheduler.runUi( () => _apply( _resolveEffectWithMessage( @@ -239,9 +241,14 @@ final class LogseqChatNativeBridge ); return ''; } - return _read( + debugPrint('[NativeBridge] resolveEffect id=$id call'); + final result = _read( _resolveEffectWithMessage(id: id, succeeded: succeeded, message: message), ); + debugPrint( + '[NativeBridge] resolveEffect id=$id returned chars=${result.length}', + ); + return result; } Pointer _resolveEffectWithMessage({ @@ -260,12 +267,21 @@ final class LogseqChatNativeBridge @override String applySnapshot(String response) { if (_runtimeScheduler.isCoreBusy) { + debugPrint( + '[NativeBridge] applySnapshot queued (core busy) ' + 'chars=${response.length}', + ); _runtimeScheduler.runUi( () => _apply(_applySnapshotWithResponse(response)), ); return ''; } - return _read(_applySnapshotWithResponse(response)); + debugPrint('[NativeBridge] applySnapshot call chars=${response.length}'); + final result = _read(_applySnapshotWithResponse(response)); + debugPrint( + '[NativeBridge] applySnapshot returned chars=${result.length}', + ); + return result; } Pointer _applySnapshotWithResponse(String response) { @@ -280,12 +296,19 @@ final class LogseqChatNativeBridge @override String applyHostUpdate({required String kind, required String payload}) { if (_runtimeScheduler.isCoreBusy) { + debugPrint('[NativeBridge] applyHostUpdate kind=$kind queued (core busy)'); _runtimeScheduler.runUi( () => _apply(_applyHostUpdateWithPayload(kind, payload)), ); return ''; } - return _read(_applyHostUpdateWithPayload(kind, payload)); + debugPrint('[NativeBridge] applyHostUpdate kind=$kind call'); + final result = _read(_applyHostUpdateWithPayload(kind, payload)); + debugPrint( + '[NativeBridge] applyHostUpdate kind=$kind returned ' + 'chars=${result.length}', + ); + return result; } Pointer _applyHostUpdateWithPayload(String kind, String payload) { diff --git a/flutter/lib/native_effect_drain.dart b/flutter/lib/native_effect_drain.dart index 7909377e..5bdc83ab 100644 --- a/flutter/lib/native_effect_drain.dart +++ b/flutter/lib/native_effect_drain.dart @@ -249,7 +249,9 @@ final class NativeEffectDrain { void _apply(String patch, String source) { if (patch.isNotEmpty) { + trace('applying patch from $source chars=${patch.length}'); applyPatch(patch); + trace('applied patch from $source'); } else { // An OCaml exception in a lui_* FFI call surfaces as an empty patch — // log the producer so a wedged pipeline is visible in the drain trace. diff --git a/shared/native/logseq_chat_core_ffi.c b/shared/native/logseq_chat_core_ffi.c index 81cacde2..bed63b89 100644 --- a/shared/native/logseq_chat_core_ffi.c +++ b/shared/native/logseq_chat_core_ffi.c @@ -11,6 +11,19 @@ #include #include +#ifdef __ANDROID__ +#include +#define LOGSEQ_CHAT_LOG(...) \ + __android_log_print(ANDROID_LOG_ERROR, "logseq_chat", __VA_ARGS__) +#else +#define LOGSEQ_CHAT_LOG(...) \ + do { \ + fprintf(stderr, "logseq_chat: "); \ + fprintf(stderr, __VA_ARGS__); \ + fputc('\n', stderr); \ + } while (0) +#endif + static pthread_once_t logseq_chat_runtime_once = PTHREAD_ONCE_INIT; static pthread_t logseq_chat_runtime_thread; static _Thread_local char *logseq_chat_response = NULL; @@ -122,29 +135,27 @@ static const char *missing_lui_callback(void) { cannot ride back in-band — the host would try to parse it as a patch. An empty patch is silently skipped by the drain, which is exactly the wedge signature we hit when an exception wedged the pipeline: log the - exception to stderr (logcat on Android, console on iOS) so the failure - is diagnosable instead of invisible. */ + exception via the platform logger (stderr does not reach logcat on + Android) so the failure is diagnosable instead of invisible. */ static const char *lui_no_callback(const char *name) { - fprintf(stderr, "logseq_chat: OCaml LUI callback is not registered: %s\n", - name); + LOGSEQ_CHAT_LOG("OCaml LUI callback is not registered: %s", name); return missing_lui_callback(); } static const char *lui_bad_argument(const char *name) { - fprintf(stderr, "logseq_chat: NULL argument passed to %s\n", name); + LOGSEQ_CHAT_LOG("NULL argument passed to %s", name); return missing_lui_callback(); } static const char *lui_exception(const char *name, value result) { char *message = caml_format_exception(Extract_exception(result)); - fprintf(stderr, "logseq_chat: OCaml exception in %s: %s\n", - name, message == NULL ? "(unprintable)" : message); + LOGSEQ_CHAT_LOG("OCaml exception in %s: %s", + name, message == NULL ? "(unprintable)" : message); return missing_lui_callback(); } static const char *lui_thread_registration_failed(void) { - fprintf(stderr, "logseq_chat: could not register calling thread " - "with the OCaml runtime\n"); + LOGSEQ_CHAT_LOG("could not register calling thread with the OCaml runtime"); return missing_lui_callback(); } @@ -417,15 +428,14 @@ int64_t logseq_chat_lui_root_node(void) { if (registration < 0) return node; const value *callback = caml_named_value("logseq_chat_lui_root_node"); if (callback == NULL) { - fprintf(stderr, "logseq_chat: OCaml LUI callback is not registered: " - "logseq_chat_lui_root_node\n"); + LOGSEQ_CHAT_LOG("OCaml LUI callback is not registered: " + "logseq_chat_lui_root_node"); } else { value result = caml_callback_exn(*callback, Val_unit); if (Is_exception_result(result)) { char *message = caml_format_exception(Extract_exception(result)); - fprintf(stderr, "logseq_chat: OCaml exception in " - "logseq_chat_lui_root_node: %s\n", - message == NULL ? "(unprintable)" : message); + LOGSEQ_CHAT_LOG("OCaml exception in logseq_chat_lui_root_node: %s", + message == NULL ? "(unprintable)" : message); } else { node = Long_val(result); }