Expose time spent collecting cycles in gc_status() (php#11523)

Author: arnaud-lb

UPGRADING

@@ -146,12 +146,20 @@ PHP 8.3 UPGRADE NOTES
 ========================================
 
 - Core:
-  . gc_status() has added the following 4 fields:
+  . gc_status() has added the following 8 fields:
     "running" => bool
     "protected" => bool
     "full" => bool
     "buffer_size" => int
-    See GH-9336
+    "application_time" => float: Total application time, in seconds (including
+    collector_time)
+    "collector_time" => float: Time spent collecting cycles, in seconds
+    (including destructor_time and free_time)
+    "destructor_time" => float: Time spent executing destructors during
+    cycle collection, in seconds
+    "free_time" => float: Time spent freeing values during cycle collection, in
+    seconds
+    See GH-9336, GH-11523
   . class_alias() now supports creating an alias of an internal class.
   . Setting `open_basedir` at runtime using `ini_set('open_basedir', ...);` no
     longer accepts paths containing the parent directory (`..`). Previously,

UPGRADING.INTERNALS

@@ -67,6 +67,10 @@ PHP 8.3 INTERNALS UPGRADE NOTES
   - zend_set_user_opcode_handler
   - zend_ssa_inference
 * Removed unused macros PHP_FNV1_32A_INIT and PHP_FNV1A_64_INIT. See GH-11114.
+* ext/standard/hrtime.h was moved to Zend/zend_hrtime.h
+  * The prefix of the PHP_HRTIME_ macros was changed to ZEND_HRTIME_
+  * The HRTIME_AVAILABLE macro was renamed to ZEND_HRTIME_AVAILABLE
+  * The php_hrtime_current() function was renamed to zend_hrtime()
 * _php_stream_dirent now has an extra d_type field that is used to store the
   directory entry type. This can be used to avoid additional stat calls for
   types when the type is already known.

Zend/tests/gc_037.phpt

@@ -12,8 +12,8 @@ gc_collect_cycles();
 gc_collect_cycles();
 var_dump(gc_status());
 ?>
---EXPECT--
-array(8) {
+--EXPECTF--
+array(12) {
   ["running"]=>
   bool(false)
   ["protected"]=>
@@ -30,8 +30,16 @@ array(8) {
   int(16384)
   ["roots"]=>
   int(1)
+  ["application_time"]=>
+  float(%f)
+  ["collector_time"]=>
+  float(%f)
+  ["destructor_time"]=>
+  float(%f)
+  ["free_time"]=>
+  float(%f)
 }
-array(8) {
+array(12) {
   ["running"]=>
   bool(false)
   ["protected"]=>
@@ -48,4 +56,12 @@ array(8) {
   int(16384)
   ["roots"]=>
   int(0)
+  ["application_time"]=>
+  float(%f)
+  ["collector_time"]=>
+  float(%f)
+  ["destructor_time"]=>
+  float(%f)
+  ["free_time"]=>
+  float(%f)
 }

Zend/tests/gc_045.phpt

@@ -45,8 +45,8 @@ for ($j = 0; $j < 10; $j++) {
 
 var_dump(gc_status());
 ?>
---EXPECT--
-array(8) {
+--EXPECTF--
+array(12) {
   ["running"]=>
   bool(false)
   ["protected"]=>
@@ -63,4 +63,12 @@ array(8) {
   int(16384)
   ["roots"]=>
   int(10000)
+  ["application_time"]=>
+  float(%f)
+  ["collector_time"]=>
+  float(%f)
+  ["destructor_time"]=>
+  float(%f)
+  ["free_time"]=>
+  float(%f)
 }

Zend/zend.c

@@ -37,6 +37,7 @@
 #include "zend_fibers.h"
 #include "zend_call_stack.h"
 #include "zend_max_execution_timer.h"
+#include "zend_hrtime.h"
 #include "Optimizer/zend_optimizer.h"
 
 static size_t global_map_ptr_last = 0;
@@ -899,6 +900,7 @@ void zend_startup(zend_utility_functions *utility_functions) /* {{{ */
 	fpsetmask(0);
 #endif
 
+	zend_startup_hrtime();
 	zend_startup_strtod();
 	zend_startup_extensions_mechanism();
 

Zend/zend_builtin_functions.c

@@ -138,7 +138,7 @@ ZEND_FUNCTION(gc_status)
 
 	zend_gc_get_status(&status);
 
-	array_init_size(return_value, 8);
+	array_init_size(return_value, 16);
 
 	add_assoc_bool_ex(return_value, "running", sizeof("running")-1, status.active);
 	add_assoc_bool_ex(return_value, "protected", sizeof("protected")-1, status.gc_protected);
@@ -148,6 +148,12 @@ ZEND_FUNCTION(gc_status)
 	add_assoc_long_ex(return_value, "threshold", sizeof("threshold")-1, (long)status.threshold);
 	add_assoc_long_ex(return_value, "buffer_size", sizeof("buffer_size")-1, (long)status.buf_size);
 	add_assoc_long_ex(return_value, "roots", sizeof("roots")-1, (long)status.num_roots);
+
+	/* Using double because zend_long may be too small on some platforms */
+	add_assoc_double_ex(return_value, "application_time", sizeof("application_time")-1, (double) status.application_time / ZEND_NANO_IN_SEC);
+	add_assoc_double_ex(return_value, "collector_time", sizeof("collector_time")-1, (double) status.collector_time / ZEND_NANO_IN_SEC);
+	add_assoc_double_ex(return_value, "destructor_time", sizeof("destructor_time")-1, (double) status.dtor_time / ZEND_NANO_IN_SEC);
+	add_assoc_double_ex(return_value, "free_time", sizeof("free_time")-1, (double) status.free_time / ZEND_NANO_IN_SEC);
 }
 /* }}} */
 

Zend/zend_gc.c

@@ -69,6 +69,7 @@
 #include "zend.h"
 #include "zend_API.h"
 #include "zend_fibers.h"
+#include "zend_hrtime.h"
 
 #ifndef ZEND_GC_DEBUG
 # define ZEND_GC_DEBUG 0
@@ -220,6 +221,11 @@ typedef struct _zend_gc_globals {
 	uint32_t gc_runs;
 	uint32_t collected;
 
+	zend_hrtime_t activated_at;
+	zend_hrtime_t collector_time;
+	zend_hrtime_t dtor_time;
+	zend_hrtime_t free_time;
+
 #if GC_BENCH
 	uint32_t root_buf_length;
 	uint32_t root_buf_peak;
@@ -439,6 +445,10 @@ static void gc_globals_ctor_ex(zend_gc_globals *gc_globals)
 
 	gc_globals->gc_runs = 0;
 	gc_globals->collected = 0;
+	gc_globals->collector_time = 0;
+	gc_globals->dtor_time = 0;
+	gc_globals->free_time = 0;
+	gc_globals->activated_at = 0;
 
 #if GC_BENCH
 	gc_globals->root_buf_length = 0;
@@ -479,6 +489,10 @@ void gc_reset(void)
 		GC_G(gc_runs) = 0;
 		GC_G(collected) = 0;
 
+		GC_G(collector_time) = 0;
+		GC_G(dtor_time) = 0;
+		GC_G(free_time) = 0;
+
 #if GC_BENCH
 		GC_G(root_buf_length) = 0;
 		GC_G(root_buf_peak) = 0;
@@ -488,6 +502,8 @@ void gc_reset(void)
 		GC_G(zval_marked_grey) = 0;
 #endif
 	}
+
+	GC_G(activated_at) = zend_hrtime();
 }
 
 ZEND_API bool gc_enable(bool enable)
@@ -1469,6 +1485,8 @@ ZEND_API int zend_gc_collect_cycles(void)
 	bool should_rerun_gc = 0;
 	bool did_rerun_gc = 0;
 
+	zend_hrtime_t start_time = zend_hrtime();
+
 rerun_gc:
 	if (GC_G(num_roots)) {
 		int count;
@@ -1482,6 +1500,7 @@ ZEND_API int zend_gc_collect_cycles(void)
 		stack.next = NULL;
 
 		if (GC_G(gc_active)) {
+			GC_G(collector_time) += zend_hrtime() - start_time;
 			return 0;
 		}
 
@@ -1561,6 +1580,7 @@ ZEND_API int zend_gc_collect_cycles(void)
 			 *
 			 * The root buffer might be reallocated during destructors calls,
 			 * make sure to reload pointers as necessary. */
+			zend_hrtime_t dtor_start_time = zend_hrtime();
 			idx = GC_FIRST_ROOT;
 			while (idx != end) {
 				current = GC_IDX2PTR(idx);
@@ -1582,11 +1602,13 @@ ZEND_API int zend_gc_collect_cycles(void)
 				}
 				idx++;
 			}
+			GC_G(dtor_time) += zend_hrtime() - dtor_start_time;
 
 			if (GC_G(gc_protected)) {
 				/* something went wrong */
 				zend_get_gc_buffer_release();
 				zend_fiber_switch_unblock();
+				GC_G(collector_time) += zend_hrtime() - start_time;
 				return 0;
 			}
 		}
@@ -1595,6 +1617,7 @@ ZEND_API int zend_gc_collect_cycles(void)
 
 		/* Destroy zvals. The root buffer may be reallocated. */
 		GC_TRACE("Destroying zvals");
+		zend_hrtime_t free_start_time = zend_hrtime();
 		idx = GC_FIRST_ROOT;
 		while (idx != end) {
 			current = GC_IDX2PTR(idx);
@@ -1645,6 +1668,8 @@ ZEND_API int zend_gc_collect_cycles(void)
 			current++;
 		}
 
+		GC_G(free_time) += zend_hrtime() - free_start_time;
+
 		zend_fiber_switch_unblock();
 
 		GC_TRACE("Collection finished");
@@ -1666,6 +1691,7 @@ ZEND_API int zend_gc_collect_cycles(void)
 finish:
 	zend_get_gc_buffer_release();
 	zend_gc_root_tmpvars();
+	GC_G(collector_time) += zend_hrtime() - start_time;
 	return total_count;
 }
 
@@ -1679,6 +1705,10 @@ ZEND_API void zend_gc_get_status(zend_gc_status *status)
 	status->threshold = GC_G(gc_threshold);
 	status->buf_size = GC_G(buf_size);
 	status->num_roots = GC_G(num_roots);
+	status->application_time = zend_hrtime() - GC_G(activated_at);
+	status->collector_time = GC_G(collector_time);
+	status->dtor_time = GC_G(dtor_time);
+	status->free_time = GC_G(free_time);
 }
 
 ZEND_API zend_get_gc_buffer *zend_get_gc_buffer_create(void) {

Zend/zend_gc.h

@@ -20,6 +20,8 @@
 #ifndef ZEND_GC_H
 #define ZEND_GC_H
 
+#include "zend_hrtime.h"
+
 #ifndef GC_BENCH
 # define GC_BENCH 0
 #endif
@@ -35,6 +37,10 @@ typedef struct _zend_gc_status {
 	uint32_t threshold;
 	uint32_t buf_size;
 	uint32_t num_roots;
+	zend_hrtime_t application_time;
+	zend_hrtime_t collector_time;
+	zend_hrtime_t dtor_time;
+	zend_hrtime_t free_time;
 } zend_gc_status;
 
 ZEND_API extern int (*gc_collect_cycles)(void);

Zend/zend_hrtime.c

@@ -0,0 +1,70 @@
+/*
+   +----------------------------------------------------------------------+
+   | Copyright (c) The PHP Group                                          |
+   +----------------------------------------------------------------------+
+   | This source file is subject to version 3.01 of the PHP license,      |
+   | that is bundled with this package in the file LICENSE, and is        |
+   | available through the world-wide-web at the following url:           |
+   | https://www.php.net/license/3_01.txt                                 |
+   | If you did not receive a copy of the PHP license and are unable to   |
+   | obtain it through the world-wide-web, please send a note to          |
+   | [email protected] so we can mail you a copy immediately.               |
+   +----------------------------------------------------------------------+
+   | Author: Niklas Keller <[email protected]>                              |
+   | Author: Anatol Belski <[email protected]>                                   |
+   +----------------------------------------------------------------------+
+ */
+
+#include "zend.h"
+#include "zend_hrtime.h"
+
+/* This file reuses code parts from the cross-platform timer library
+	Public Domain - 2011 Mattias Jansson / Rampant Pixels */
+
+#if ZEND_HRTIME_PLATFORM_POSIX
+
+# include <unistd.h>
+# include <time.h>
+# include <string.h>
+
+#elif ZEND_HRTIME_PLATFORM_WINDOWS
+
+# define WIN32_LEAN_AND_MEAN
+
+double zend_hrtime_timer_scale = .0;
+
+#elif ZEND_HRTIME_PLATFORM_APPLE
+
+# include <mach/mach_time.h>
+# include <string.h>
+mach_timebase_info_data_t zend_hrtime_timerlib_info = {
+	.numer = 0,
+	.denom = 1,
+};
+
+#elif ZEND_HRTIME_PLATFORM_HPUX
+
+# include <sys/time.h>
+
+#elif ZEND_HRTIME_PLATFORM_AIX
+
+# include <sys/time.h>
+# include <sys/systemcfg.h>
+
+#endif
+
+void zend_startup_hrtime(void)
+{
+#if ZEND_HRTIME_PLATFORM_WINDOWS
+
+	LARGE_INTEGER tf = {0};
+	if (QueryPerformanceFrequency(&tf) || 0 != tf.QuadPart) {
+		zend_hrtime_timer_scale = (double)ZEND_NANO_IN_SEC / (zend_hrtime_t)tf.QuadPart;
+	}
+
+#elif ZEND_HRTIME_PLATFORM_APPLE
+
+	mach_timebase_info(&zend_hrtime_timerlib_info);
+
+#endif
+}