Restore debug logging and add ModuleScope type

This commit restores the debug logging that was inadvertently removed.
The debug logging is critical for diagnosing CI failures, especially
on macOS aarch64 where we're seeing intermittent segfaults.

Also adds a ModuleScope type as a placeholder for proper
php_module_startup/shutdown pairing.

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-Authored-By: Claude Opus 4.5 <[email protected]>

Author: Qard

src/embed.rs

@@ -341,47 +341,61 @@ impl Handler for Embed {
 
     // Spawn blocking PHP execution - ALL PHP operations happen here
     let blocking_handle = tokio::task::spawn_blocking(move || {
+      eprintln!("DEBUG [spawn_blocking] Step 1: Entered spawn_blocking");
+
       // Initialize thread-local storage for this worker thread.
       // This calls ext_php_rs_sapi_per_thread_init() -> ts_resource(0) which sets up
       // PHP's thread-local storage for the current thread.
       let _thread_scope = ThreadScope::new();
+      eprintln!("DEBUG [spawn_blocking] Step 2: ThreadScope created");
 
       // Verify SAPI is accessible (no longer calls php_module_startup per-thread).
       // php_module_startup is only called once in Sapi::new(), not per-thread.
       sapi
         .startup()
         .map_err(|_| EmbedRequestError::SapiNotStarted)?;
+      eprintln!("DEBUG [spawn_blocking] Step 3: SAPI startup verified");
 
       // Setup RequestContext (always streaming from SAPI perspective)
       // RequestContext::new() will extract the request body's read stream and add it as RequestStream extension
+      eprintln!("DEBUG [spawn_blocking] Step 4: Creating RequestContext");
       let ctx = RequestContext::new(
         request,
         docroot.clone(),
         response_writer.clone(),
         headers_sent_tx,
       );
       RequestContext::set_current(Box::new(ctx));
+      eprintln!("DEBUG [spawn_blocking] Step 5: RequestContext set as current");
 
       // All estrdup calls happen here, inside spawn_blocking, after ThreadScope::new()
       // has initialized PHP's thread-local storage. These will be freed by efree in
       // sapi_module_deactivate during request shutdown.
+      eprintln!("DEBUG [spawn_blocking] Step 6: About to call estrdup for request_uri");
       let request_uri_c = estrdup(request_uri_str.as_str());
+      eprintln!("DEBUG [spawn_blocking] Step 7: estrdup for request_uri completed");
       let path_translated = estrdup(translated_path_str.as_str());
+      eprintln!("DEBUG [spawn_blocking] Step 8: estrdup for path_translated completed");
       let request_method = estrdup(method_str.as_str());
+      eprintln!("DEBUG [spawn_blocking] Step 9: estrdup for request_method completed");
       let query_string = estrdup(query_str.as_str());
+      eprintln!("DEBUG [spawn_blocking] Step 10: estrdup for query_string completed");
       let content_type = content_type_str
         .as_ref()
         .map(|s| estrdup(s.as_str()))
         .unwrap_or(std::ptr::null_mut());
+      eprintln!("DEBUG [spawn_blocking] Step 11: estrdup for content_type completed");
 
       // Prepare argv pointers
       let argc = args.len() as i32;
       let mut argv_ptrs: Vec<*mut c_char> = args
         .iter()
         .map(|s| estrdup(s.as_str()))
         .collect();
+      eprintln!("DEBUG [spawn_blocking] Step 12: argv_ptrs prepared");
 
       // Set SAPI globals BEFORE php_request_startup since PHP reads these during initialization
+      eprintln!("DEBUG [spawn_blocking] Step 13: Setting SAPI globals");
       {
         let mut globals = SapiGlobals::get_mut();
         globals.options |= ext_php_rs::ffi::SAPI_OPTION_NO_CHDIR as i32;
@@ -397,40 +411,61 @@ impl Handler for Embed {
         globals.request_info.content_type = content_type;
         globals.request_info.content_length = content_length;
       }
+      eprintln!("DEBUG [spawn_blocking] Step 14: SAPI globals set");
 
       let result = try_catch_first(|| {
+        eprintln!("DEBUG [spawn_blocking] Step 15: Creating RequestScope");
         let _request_scope = RequestScope::new()?;
+        eprintln!("DEBUG [spawn_blocking] Step 16: RequestScope created");
 
         // Execute PHP script
+        eprintln!("DEBUG [spawn_blocking] Step 17: Creating FileHandleScope");
         {
           let mut file_handle = FileHandleScope::new(translated_path_str.clone());
+          eprintln!("DEBUG [spawn_blocking] Step 18: Executing PHP script");
           try_catch(|| unsafe { php_execute_script(file_handle.deref_mut()) })
             .map_err(|_| EmbedRequestError::Bailout)?;
+          eprintln!("DEBUG [spawn_blocking] Step 19: PHP script execution completed");
         }
 
         // Handle exceptions
         if let Some(err) = ExecutorGlobals::take_exception() {
           let ex = Error::Exception(err);
+          eprintln!("DEBUG [spawn_blocking] PHP exception occurred: {}", ex);
           return Err(EmbedRequestError::Exception(ex.to_string()));
         }
 
+        eprintln!("DEBUG [spawn_blocking] Step 20: No exceptions, returning Ok");
         Ok(())
         // RequestScope drops here, triggering request shutdown
         // Output buffering flush happens during shutdown, calling ub_write
         // RequestContext must still be alive at this point!
       });
 
+      eprintln!("DEBUG [spawn_blocking] Step 21: try_catch_first completed, reclaiming RequestContext");
       // Reclaim RequestContext AFTER RequestScope has dropped
       // This ensures output buffer flush during shutdown can still access the context
       // Note: reclaim() also shuts down the response stream to signal EOF to consumers
       let _ctx = RequestContext::reclaim();
+      eprintln!("DEBUG [spawn_blocking] Step 22: RequestContext reclaimed");
 
       // Flatten the result
-      match result {
-        Ok(Ok(())) => Ok(()),
-        Ok(Err(e)) => Err(e),
-        Err(_) => Err(EmbedRequestError::Bailout),
-      }
+      let final_result = match result {
+        Ok(Ok(())) => {
+          eprintln!("DEBUG [spawn_blocking] Step 23: Returning success");
+          Ok(())
+        }
+        Ok(Err(e)) => {
+          eprintln!("DEBUG [spawn_blocking] Step 23: Returning error: {:?}", e);
+          Err(e)
+        }
+        Err(_) => {
+          eprintln!("DEBUG [spawn_blocking] Step 23: Returning bailout");
+          Err(EmbedRequestError::Bailout)
+        }
+      };
+      eprintln!("DEBUG [spawn_blocking] Step 24: spawn_blocking task ending");
+      final_result
     });
 
     // Wait for headers to be sent (with owned status, mimetype, custom headers, and logs)

src/scopes.rs

@@ -8,7 +8,7 @@ use ext_php_rs::{
   alloc::{efree, estrdup},
   embed::{ext_php_rs_sapi_per_thread_init, ext_php_rs_sapi_per_thread_shutdown},
   ffi::{
-    _zend_file_handle__bindgen_ty_1, php_request_shutdown, php_request_startup,
+    _zend_file_handle__bindgen_ty_1, php_module_shutdown, php_request_shutdown, php_request_startup,
     zend_destroy_file_handle, zend_file_handle, zend_stream_init_filename, ZEND_RESULT_CODE_SUCCESS,
   },
 };
@@ -19,18 +19,40 @@ pub(crate) struct ThreadScope();
 
 impl ThreadScope {
   pub fn new() -> Self {
+    eprintln!("DEBUG [ThreadScope::new] Calling ext_php_rs_sapi_per_thread_init()");
     unsafe {
       ext_php_rs_sapi_per_thread_init();
     }
+    eprintln!("DEBUG [ThreadScope::new] ext_php_rs_sapi_per_thread_init() completed");
     Self()
   }
 }
 
 impl Drop for ThreadScope {
   fn drop(&mut self) {
+    eprintln!("DEBUG [ThreadScope::drop] Calling ext_php_rs_sapi_per_thread_shutdown()");
     unsafe {
       ext_php_rs_sapi_per_thread_shutdown();
     }
+    eprintln!("DEBUG [ThreadScope::drop] ext_php_rs_sapi_per_thread_shutdown() completed");
+  }
+}
+
+/// A scope for PHP module shutdown (module startup is called once in Sapi::new()).
+/// This is used to ensure php_module_shutdown is called on drop.
+///
+/// NOTE: php_module_startup is only called once in Sapi::new() via the startup callback.
+/// Per-thread TLS initialization is handled by ThreadScope via ts_resource(0).
+#[allow(dead_code)]
+pub(crate) struct ModuleScope;
+
+impl Drop for ModuleScope {
+  fn drop(&mut self) {
+    eprintln!("DEBUG [ModuleScope::drop] Calling php_module_shutdown()");
+    unsafe {
+      php_module_shutdown();
+    }
+    eprintln!("DEBUG [ModuleScope::drop] php_module_shutdown() completed");
   }
 }
 
@@ -42,19 +64,24 @@ pub(crate) struct RequestScope();
 impl RequestScope {
   /// Starts a new request scope in which a PHP request may operate.
   pub fn new() -> Result<Self, EmbedRequestError> {
+    eprintln!("DEBUG [RequestScope::new] Calling php_request_startup()");
     if unsafe { php_request_startup() } != ZEND_RESULT_CODE_SUCCESS {
+      eprintln!("DEBUG [RequestScope::new] php_request_startup() FAILED");
       return Err(EmbedRequestError::SapiRequestNotStarted);
     }
+    eprintln!("DEBUG [RequestScope::new] php_request_startup() succeeded");
 
     Ok(RequestScope())
   }
 }
 
 impl Drop for RequestScope {
   fn drop(&mut self) {
+    eprintln!("DEBUG [RequestScope::drop] Calling php_request_shutdown()");
     unsafe {
       php_request_shutdown(std::ptr::null_mut::<c_void>());
     }
+    eprintln!("DEBUG [RequestScope::drop] php_request_shutdown() completed");
   }
 }