-
Notifications
You must be signed in to change notification settings - Fork 7.9k
Expose time spent collecting cycles in gc_status() #11523
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Merged
Merged
Changes from all commits
Commits
Show all changes
14 commits
Select commit
Hold shift + click to select a range
03fa600
Move php_hrtime_current() to zend_monotonic_time()
arnaud-lb 01653bf
Expose time spend collecting cycles in gc_status()
arnaud-lb eba988b
Return failure
arnaud-lb 41f3252
Update initial array size
arnaud-lb c7fc79e
Rename zend_time -> zend_hrtime
arnaud-lb 92c6080
Fix windows build
arnaud-lb 5e514e6
Actually rename
arnaud-lb c6c9a9d
UPGRADING
arnaud-lb 4e8c2ed
Fix windows build
arnaud-lb 5d73e31
Initialize activated_at in globals ctors
arnaud-lb f580e4d
Includes first
arnaud-lb 3002416
UPGRADING: typos
arnaud-lb 82c5be3
Merge branch 'master' into gc-timing
sebastianbergmann 0713de3
Review
arnaud-lb File filter
Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
There are no files selected for viewing
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -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; | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Is setting |
||
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) { | ||
|
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -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 | | ||
| license@php.net so we can mail you a copy immediately. | | ||
+----------------------------------------------------------------------+ | ||
| Author: Niklas Keller <kelunik@php.net> | | ||
| Author: Anatol Belski <ab@php.net> | | ||
+----------------------------------------------------------------------+ | ||
*/ | ||
|
||
#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 | ||
} |
Oops, something went wrong.
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
the init size above should be updated
also are/can these strings be interned for better perf?
what is the time measurement and
gc_status()
itself overhead?There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I've updated the initial array size, thank you.
Regarding the time measurement overhead:
The synthetic benchmarks here and here show no significant overhead over multiple runs. The number of 10k nodes was chosen because this is the default GC threshold. Applications will typically have more nodes to scan, and their
measurement_overhead/actual_work
ratio will be lower.I've seen no significant overhead on a long running application.
Regarding the overhead on
gc_status()
itself, it would matter if the function was called a high number of times during a request. Do you think it will be the case?There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
In PHPUnit 10,
gc_status()
is called for each event that is emitted. This is "a lot", but IMO perfectly fine in a development context.There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I see no slowdown on the PHPUnit 10 test suite. However,
gc_status()
was called only 128 times. Is there a configuration that would cause more events to be triggered?There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I was looking at the wrong file:
gc_status()
is actually called more than 19k times during the test suite and the changes in this PR caused no slowdown.There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
PHPUnit's test suite (
main
branch) currently has 2845 tests. For each test, multiple events are emitted. For each event,gc_status()
is called. I am confused that you only see 128 calls.There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Aha! :)