fix: hook write with re-entrancy guard to prevent preemption during logging, revert change_state conditional reorder

Agent-Logs-Url: https://github.com/acl-dev/open-coroutine/sessions/c679f7fd-4c3d-4a1c-a07d-637ba7b9fc00

Co-authored-by: loongs-zhang <38336731+loongs-zhang@users.noreply.github.com>

Author: Copilot

core/src/coroutine/state.rs

@@ -18,24 +18,11 @@ where
         new_state: CoroutineState<Yield, Return>,
     ) -> CoroutineState<Yield, Return> {
         let old_state = self.state.replace(new_state);
-        if matches!(new_state, CoroutineState::Running) {
-            //先打印日志再通知监听器，避免在QEMU等慢速平台上的活锁问题
-            // Log before notifying: MonitorListener starts the 10ms preemption
-            // timer on Running state. On QEMU, info!() takes >10ms, so logging
-            // first ensures the timer starts after the slow I/O completes.
-            info!("{} {:?}->{:?}", self.name(), old_state, new_state);
-            self.on_state_changed(self, old_state, new_state);
+        self.on_state_changed(self, old_state, new_state);
+        if let CoroutineState::Error(_) = new_state {
+            error!("{} {:?}->{:?}", self.name(), old_state, new_state);
         } else {
-            //先通知监听器再打印日志，确保抢占定时器在日志I/O之前被移除
-            // Notify before logging: MonitorListener removes the NOTIFY_NODE for
-            // non-Running states. Removing it first prevents SIGURG from arriving
-            // during the potentially slow log I/O.
-            self.on_state_changed(self, old_state, new_state);
-            if let CoroutineState::Error(_) = new_state {
-                error!("{} {:?}->{:?}", self.name(), old_state, new_state);
-            } else {
-                info!("{} {:?}->{:?}", self.name(), old_state, new_state);
-            }
+            info!("{} {:?}->{:?}", self.name(), old_state, new_state);
         }
         old_state
     }

core/src/syscall/unix/mod.rs

@@ -2,6 +2,25 @@ use dashmap::DashMap;
 use once_cell::sync::Lazy;
 use std::ffi::c_int;
 
+//防止重入：info!()/error!()内部会调用write()，如果write被hook了，
+//会导致无限递归或嵌套状态转换。当检测到重入时，直接调用内部系统调用跳过facade逻辑。
+// Re-entrancy guard: info!()/error!() internally call write(). If write is hooked,
+// this causes infinite recursion or nested state transitions that corrupt coroutine state.
+// When re-entrancy is detected, bypass the facade and call the inner syscall directly.
+thread_local! {
+    static IN_FACADE: std::cell::Cell<bool> = const { std::cell::Cell::new(false) };
+}
+
+#[inline]
+pub fn in_facade() -> bool {
+    IN_FACADE.get()
+}
+
+#[inline]
+pub fn set_in_facade(val: bool) {
+    IN_FACADE.set(val);
+}
+
 macro_rules! impl_syscall {
     (
         $facade_struct_name:ident, $iocp_struct_name: ident, $nio_struct_name: ident, $raw_struct_name: ident,
@@ -97,7 +116,18 @@ macro_rules! impl_facade {
                 fn_ptr: Option<&extern "C" fn($($arg_type),*) -> $result>,
                 $($arg: $arg_type),*
             ) -> $result {
+                if $crate::syscall::in_facade() {
+                    return self.inner.$syscall(fn_ptr, $($arg, )*);
+                }
                 let syscall = $crate::common::constants::SyscallName::$syscall;
+                //在日志和状态变更期间设置防重入标志，因为info!()/error!()内部会
+                //调用write()，co.syscall()/co.running()内部会调用change_state()
+                //再调用info!()，这些都可能触发hooked write导致无限递归
+                // Set re-entrancy guard during logging and state changes because:
+                // - info!()/error!() internally call write()
+                // - co.syscall()/co.running() call change_state() which calls info!()
+                // Both can trigger hooked write causing infinite recursion.
+                $crate::syscall::set_in_facade(true);
                 $crate::info!("enter syscall {}", syscall);
                 if let Some(co) = $crate::scheduler::SchedulableCoroutine::current() {
                     let new_state = $crate::common::constants::SyscallState::Executing;
@@ -107,13 +137,16 @@ macro_rules! impl_facade {
                         );
                     }
                 }
+                $crate::syscall::set_in_facade(false);
                 let r = self.inner.$syscall(fn_ptr, $($arg, )*);
+                $crate::syscall::set_in_facade(true);
                 if let Some(co) = $crate::scheduler::SchedulableCoroutine::current() {
                     if co.running().is_err() {
                         $crate::error!("{} change to running state failed !", co.name());
                     }
                 }
                 $crate::info!("exit syscall {} {:?} {}", syscall, r, std::io::Error::last_os_error());
+                $crate::syscall::set_in_facade(false);
                 r
             }
         }

hook/src/syscall/unix.rs

@@ -83,6 +83,40 @@ impl_hook!(RENAMEAT2, renameat2(olddirfd: c_int, oldpath: *const c_char, newdirf
 // impl_hook!(POLL, poll(fds: *mut pollfd, nfds: nfds_t, timeout: c_int) -> c_int);
 
 // NOTE: unhook write/pthread_mutex_lock/pthread_mutex_unlock due to stack overflow or bug
-// impl_hook!(WRITE, write(fd: c_int, buf: *const c_void, count: size_t) -> ssize_t);
 // impl_hook!(PTHREAD_MUTEX_LOCK, pthread_mutex_lock(lock: *mut pthread_mutex_t) -> c_int);
 // impl_hook!(PTHREAD_MUTEX_UNLOCK, pthread_mutex_unlock(lock: *mut pthread_mutex_t) -> c_int);
+
+//write需要特殊的hook实现：stdout/stderr的write由日志框架触发，
+//必须绕过facade直接调用原始write，否则facade内部的info!()会再次
+//触发write导致stdout RefCell重复借用。其他fd正常走facade。
+// write needs a custom hook: writes to stdout/stderr are triggered by
+// the logging framework. They must bypass the facade and call raw write
+// directly; otherwise the facade's info!() would re-trigger write,
+// causing stdout's RefCell to be double-borrowed. Other fds go through
+// the facade normally.
+#[no_mangle]
+pub extern "C" fn write(fd: c_int, buf: *const c_void, count: size_t) -> ssize_t {
+    static WRITE: once_cell::sync::Lazy<extern "C" fn(c_int, *const c_void, size_t) -> ssize_t> =
+        once_cell::sync::Lazy::new(|| unsafe {
+            let symbol = std::ffi::CString::new("write")
+                .unwrap_or_else(|_| panic!("can not transfer \"write\" to CString"));
+            let ptr = libc::dlsym(libc::RTLD_NEXT, symbol.as_ptr());
+            assert!(!ptr.is_null(), "syscall \"write\" not found !");
+            std::mem::transmute(ptr)
+        });
+    let fn_ptr = once_cell::sync::Lazy::force(&WRITE);
+    // stdout(1)/stderr(2)的write由日志框架触发，必须绕过facade
+    // Bypass facade for stdout/stderr — these are logging fds
+    if fd == libc::STDOUT_FILENO || fd == libc::STDERR_FILENO
+        || open_coroutine_core::syscall::in_facade()
+    {
+        return (fn_ptr)(fd, buf, count);
+    }
+    if crate::hook()
+        || open_coroutine_core::scheduler::SchedulableCoroutine::current().is_some()
+        || cfg!(feature = "ci")
+    {
+        return open_coroutine_core::syscall::write(Some(fn_ptr), fd, buf, count);
+    }
+    (fn_ptr)(fd, buf, count)
+}