ohos/android: Redirect stdout/stderr to log sink (#32858)

* ohos: redirect stdout/stderr to logging sink

Based on the existing android `redirect_stdout_to_logcat` implementation,
but using the safe abstractions from `nix` and dumping to the `log` sink,
instead of directly writing the log.

Signed-off-by: Jonathan Schwender <jonathan.schwender@huawei.com>

* android: Use new shared implementation for logcat redirection.

Signed-off-by: Jonathan Schwender <jonathan.schwender@huawei.com>

* servoshell: Register cfg(production)

Signed-off-by: Jonathan Schwender <jonathan.schwender@huawei.com>

* Update ports/servoshell/egl/log.rs

Co-authored-by: Martin Robinson <mrobinson@igalia.com>
Signed-off-by: Jonathan Schwender <55576758+jschwe@users.noreply.github.com>

* Change info! to debug! to match original behavior on android

Signed-off-by: Jonathan Schwender <jonathan.schwender@huawei.com>

---------

Signed-off-by: Jonathan Schwender <jonathan.schwender@huawei.com>
Signed-off-by: Jonathan Schwender <55576758+jschwe@users.noreply.github.com>
Co-authored-by: Martin Robinson <mrobinson@igalia.com>

Cargo.lock

@@ -6193,6 +6193,7 @@ dependencies = [
  "log",
  "napi-derive-ohos",
  "napi-ohos",
+ "nix",
  "ohos-sys",
  "raw-window-handle",
  "serde_json",

Cargo.toml

@@ -81,6 +81,7 @@ mime = "0.3.13"
 mime_guess = "2.0.5"
 mozangle = "0.5.1"
 net_traits = { path = "components/shared/net" }
+nix = "0.29"
 num-traits = "0.2"
 num_cpus = "1.1.0"
 parking_lot = "0.12"

components/background_hang_monitor/Cargo.toml

@@ -26,5 +26,5 @@ serde_json = { workspace = true }
 mach2 = "0.4"
 
 [target.'cfg(all(target_os = "linux", not(any(target_arch = "arm", target_arch = "aarch64", target_env = "ohos"))))'.dependencies]
-nix = { version = "0.29", features = ["signal"] }
+nix = { workspace = true, features = ["signal"] }
 unwind-sys = "0.1.4"

ports/servoshell/Cargo.toml

@@ -66,9 +66,6 @@ android_logger = "0.14"
 ipc-channel = { workspace = true }
 jni = "0.21.1"
 libloading = "0.8"
-serde_json = { workspace = true }
-surfman = { workspace = true, features = ["sm-angle-default"] }
-webxr = { git = "https://github.com/servo/webxr" }
 
 
 [target.'cfg(not(target_os = "android"))'.dependencies]
@@ -82,11 +79,14 @@ ipc-channel = { workspace = true, features = ["force-inprocess"] }
 hilog = "0.1.0"
 napi-derive-ohos = "0.0.9"
 napi-ohos = "0.1"
-serde_json = { workspace = true }
-surfman = { workspace = true, features = ["sm-angle-default"] }
-webxr = { git = "https://github.com/servo/webxr" }
 ohos-sys = { version = "0.2.1", features = ["xcomponent"] }
 
+[target.'cfg(any(target_os = "android", target_env = "ohos"))'.dependencies]
+nix = { workspace = true, features = ["fs"] }
+surfman = { workspace = true, features = ["sm-angle-default"] }
+serde_json = { workspace = true }
+webxr = { git = "https://github.com/servo/webxr" }
+
 
 [target.'cfg(not(any(target_os = "android", target_env = "ohos")))'.dependencies]
 # For optional feature servo_allocator/use-system-allocator
@@ -117,3 +117,6 @@ sig = "1.0"
 webxr = { git = "https://github.com/servo/webxr", features = ["ipc", "glwindow", "headless", "openxr-api"] }
 windows-sys = { workspace = true, features = ["Win32_Graphics_Gdi"] }
 libservo = { path = "../../components/servo", features = ["no-wgl"] }
+
+[lints.rust]
+unexpected_cfgs = { level = "allow", check-cfg = ['cfg(production)'] }

ports/servoshell/egl/android.rs

@@ -93,6 +93,8 @@ pub extern "C" fn Java_org_servo_servoview_JNIServo_init<'local>(
             "servo",
             "servoshell",
             "servoshell::egl:gl_glue",
+            // Show redirected stdout / stderr by default
+            "servoshell::egl::log",
             // Show JS errors by default.
             "script::dom::bindings::error",
             // Show GL errors by default.
@@ -120,7 +122,12 @@ pub extern "C" fn Java_org_servo_servoview_JNIServo_init<'local>(
 
     info!("init");
 
-    redirect_stdout_to_logcat();
+    // We only redirect stdout and stderr for non-production builds, since it is
+    // only used for debugging purposes. This saves us one thread in production.
+    #[cfg(not(production))]
+    if let Err(e) = super::log::redirect_stdout_and_stderr() {
+        error!("Failed to redirect stdout and stderr to logcat due to: {e:?}");
+    }
 
     let callbacks_ref = match env.new_global_ref(callbacks_obj) {
         Ok(r) => r,
@@ -692,91 +699,6 @@ extern "C" {
     pub fn __android_log_write(prio: c_int, tag: *const c_char, text: *const c_char) -> c_int;
 }
 
-fn redirect_stdout_to_logcat() {
-    // The first step is to redirect stdout and stderr to the logs.
-    // We redirect stdout and stderr to a custom descriptor.
-    let mut pfd: [c_int; 2] = [0, 0];
-    unsafe {
-        pipe(pfd.as_mut_ptr());
-        dup2(pfd[1], 1);
-        dup2(pfd[1], 2);
-    }
-
-    let descriptor = pfd[0];
-
-    // Then we spawn a thread whose only job is to read from the other side of the
-    // pipe and redirect to the logs.
-    let _detached = thread::spawn(move || {
-        const BUF_LENGTH: usize = 512;
-        let mut buf = vec![b'\0' as c_char; BUF_LENGTH];
-
-        // Always keep at least one null terminator
-        const BUF_AVAILABLE: usize = BUF_LENGTH - 1;
-        let buf = &mut buf[..BUF_AVAILABLE];
-
-        let mut cursor = 0_usize;
-
-        let tag = c"servoshell".as_ptr() as _;
-
-        loop {
-            let result = {
-                let read_into = &mut buf[cursor..];
-                unsafe {
-                    read(
-                        descriptor,
-                        read_into.as_mut_ptr() as *mut _,
-                        read_into.len(),
-                    )
-                }
-            };
-
-            let end = if result == 0 {
-                return;
-            } else if result < 0 {
-                unsafe {
-                    __android_log_write(
-                        3,
-                        tag,
-                        c"error in log thread; closing".as_ptr() as *const _,
-                    );
-                }
-                return;
-            } else {
-                result as usize + cursor
-            };
-
-            // Only modify the portion of the buffer that contains real data.
-            let buf = &mut buf[0..end];
-
-            if let Some(last_newline_pos) = buf.iter().rposition(|&c| c == b'\n' as c_char) {
-                buf[last_newline_pos] = b'\0' as c_char;
-                unsafe {
-                    __android_log_write(3, tag, buf.as_ptr());
-                }
-                if last_newline_pos < buf.len() - 1 {
-                    let pos_after_newline = last_newline_pos + 1;
-                    let len_not_logged_yet = buf[pos_after_newline..].len();
-                    for j in 0..len_not_logged_yet as usize {
-                        buf[j] = buf[pos_after_newline + j];
-                    }
-                    cursor = len_not_logged_yet;
-                } else {
-                    cursor = 0;
-                }
-            } else if end == BUF_AVAILABLE {
-                // No newline found but the buffer is full, flush it anyway.
-                // `buf.as_ptr()` is null-terminated by BUF_LENGTH being 1 less than BUF_AVAILABLE.
-                unsafe {
-                    __android_log_write(3, tag, buf.as_ptr());
-                }
-                cursor = 0;
-            } else {
-                cursor = end;
-            }
-        }
-    });
-}
-
 fn throw(env: &mut JNIEnv, err: &str) {
     if let Err(e) = env.throw(("java/lang/Exception", err)) {
         warn!(

ports/servoshell/egl/log.rs

@@ -0,0 +1,96 @@
+/* This Source Code Form is subject to the terms of the Mozilla Public
+ * License, v. 2.0. If a copy of the MPL was not distributed with this
+ * file, You can obtain one at https://mozilla.org/MPL/2.0/. */
+
+//! Helper Module to redirect stdout/stderr to the logging sink
+
+use std::os::fd::{AsRawFd, IntoRawFd, RawFd};
+use std::thread;
+
+use log::{debug, error, info, warn};
+
+#[derive(Debug)]
+#[allow(dead_code)]
+pub(crate) enum LogRedirectError {
+    CreatePipeFailed(nix::Error),
+    RedirectToPipeFailed(nix::Error),
+}
+
+/// Redirect stdout and stderr to the logging system
+pub(crate) fn redirect_stdout_and_stderr() -> Result<(), LogRedirectError> {
+    fn log_raw_msg(raw_msg: &[u8]) {
+        if let Ok(utf8_msg) = std::str::from_utf8(raw_msg) {
+            debug!("{utf8_msg}");
+        } else {
+            // Note: This could happen if the message is long, and we hit the length
+            // limitation in the middle of a utf-8 codepoint. We could try to handle this
+            // by using `error.valid_up_to()`, but lets see first if we hit this problem
+            // in practice.
+            warn!("Dropping 1 log message due to invalid encoding.");
+            debug!("Raw byte content: {raw_msg:?}")
+        }
+    }
+
+    // The first step is to redirect stdout and stderr to the logs.
+    // We redirect stdout and stderr to a custom descriptor.
+    let (readerfd, writerfd) =
+        nix::unistd::pipe().map_err(|e| LogRedirectError::CreatePipeFailed(e))?;
+    // Leaks the writer fd. We want to log for the whole program lifetime.
+    let raw_writerfd = writerfd.into_raw_fd();
+    let _fd = nix::unistd::dup2(raw_writerfd, RawFd::from(1))
+        .map_err(|e| LogRedirectError::RedirectToPipeFailed(e))?;
+    let _fd = nix::unistd::dup2(raw_writerfd, RawFd::from(2))
+        .map_err(|e| LogRedirectError::RedirectToPipeFailed(e))?;
+
+    // Then we spawn a thread whose only job is to read from the other side of the
+    // pipe and redirect to the logs.
+    let _detached = thread::spawn(move || {
+        const BUF_LENGTH: usize = 512;
+        let mut buf = vec![b'\0'; BUF_LENGTH];
+
+        let mut cursor = 0_usize;
+
+        loop {
+            let result = {
+                let read_into = &mut buf[cursor..];
+                nix::unistd::read(readerfd.as_raw_fd(), read_into)
+            };
+
+            let end = match result {
+                Ok(0) => {
+                    info!("Log pipe closed. Terminating log thread");
+                    return;
+                },
+                Ok(bytes) => bytes + cursor,
+                Err(nix::errno::Errno::EINTR) => continue,
+                Err(e) => {
+                    error!("Failed to read from redirected stdout/stderr pipe due to {e:?}. Closing log thread");
+                    return;
+                },
+            };
+
+            // Only modify the portion of the buffer that contains real data.
+            let buf = &mut buf[0..end];
+
+            if let Some(last_newline_pos) = buf.iter().rposition(|&c| c == b'\n') {
+                log_raw_msg(&buf[0..last_newline_pos]);
+
+                if last_newline_pos < buf.len() {
+                    let pos_after_newline = last_newline_pos + 1;
+                    let len_not_logged_yet = buf[pos_after_newline..].len();
+                    buf.copy_within(pos_after_newline..end, 0);
+                    cursor = len_not_logged_yet;
+                } else {
+                    cursor = 0;
+                }
+            } else if end == BUF_LENGTH {
+                // No newline found but the buffer is full, flush it anyway.
+                log_raw_msg(buf);
+                cursor = 0;
+            } else {
+                cursor = end;
+            }
+        }
+    });
+    Ok(())
+}

ports/servoshell/egl/mod.rs

@@ -11,6 +11,8 @@ mod android;
 #[cfg(target_env = "ohos")]
 mod ohos;
 
+mod log;
+
 mod host_trait;
 mod resources;
 mod servo_glue;

ports/servoshell/egl/ohos.rs

@@ -331,6 +331,8 @@ fn initialize_logging_once() {
             "servo",
             "servoshell",
             "servoshell::egl:gl_glue",
+            // Show redirected stdout / stderr by default
+            "servoshell::egl::log",
             // Show JS errors by default.
             "script::dom::bindings::error",
             // Show GL errors by default.
@@ -373,6 +375,13 @@ fn initialize_logging_once() {
 
             let _ = crate::backtrace::print_ohos();
         }));
+
+        // We only redirect stdout and stderr for non-production builds, since it is
+        // only used for debugging purposes. This saves us one thread in production.
+        #[cfg(not(production))]
+        if let Err(e) = super::log::redirect_stdout_and_stderr() {
+            error!("Failed to redirect stdout and stderr to hilog due to: {e:?}");
+        }
     })
 }