longxinH / xhprof

PHP7/PHP8 support
http://pecl.php.net/package/xhprof
Apache License 2.0
1.08k stars 167 forks source link

Fixed clocks to microseconds conversion on Mac #75

Closed mikhainin closed 1 year ago

mikhainin commented 1 year ago

If we take https://opensource.apple.com/source/Libc/Libc-1158.1.2/gen/clock_gettime.c.auto.html for reference, Indeed, conversion to usecs looks like

mach_timebase_info(&tb_info)
(mach_absolute_time() * tb_info.numer) / tb_info.denom;

However, in our case, we store the timebase info and then use it as:

mach_absolute_time() / X

It looks like to get the same result, X should be calculated as:

X = tb_info.denom / tb_info.numer; 

After this, tests on Mac started passing :)

longxinH commented 1 year ago

Hi, can you provide examples of test failures under macos?

mikhainin commented 1 year ago

Sure,

=====================================================================
FAILED TEST SUMMARY
---------------------------------------------------------------------
XHProf: Timer Tests
Author: Kannan [tests/xhprof_005.phpt]
XHProf: Sampling Mode Test
Author: kannan [tests/xhprof_008.phpt]
XHProf: Test Sampling Interval
Author: longxinhui [tests/xhprof_013.phpt]
=====================================================================
$ cat tests/xhprof_005.diff 
     Verifying sleep_10000_micro...
002+ Failed sleep_10000_micro. Expected: 10000 microsecs. Actual: 7 microsecs.
002- OK: sleep_10000_micro
     -------------
     Verifying sleep_20000_micro...
005+ Failed sleep_20000_micro. Expected: 20000 microsecs. Actual: 15 microsecs.
005- OK: sleep_20000_micro
     -------------
     Verifying sleep_50000_micro...
008+ Failed sleep_50000_micro. Expected: 50000 microsecs. Actual: 32 microsecs.
008- OK: sleep_50000_micro
     -------------%                                                                                                                                                                           
$ cat tests/xhprof_008.diff 
001+ Test failed
001- Test passed
002+ Count of usleep samples in one call to goo(): 0
003+ Count of usleep samples in two calls to goo(): 0
004+ Samples in one call to goo(): 
005+ array(0) {
006+ }
007+ Samples in two calls to goo(): 
008+ array(0) {
009+ }%                                                                                                                                                                                       
cat tests/xhprof_013.diff 
001+ Warning: Undefined array key 1 in /Users/mikhailgalanin/src/xhprof/extension/tests/xhprof_013.php on line 23
001- Test passed
002+ 
003+ Warning: Undefined array key 0 in /Users/mikhailgalanin/src/xhprof/extension/tests/xhprof_013.php on line 23
004+ array(0) {
005+ }
006+ 0.000000%                                                                                                                                                                                

If we apply the PR, only one test keeps failing

$ cat tests/xhprof_005.diff
     Verifying sleep_10000_micro...
002+ Failed sleep_10000_micro. Expected: 10000 microsecs. Actual: 12528 microsecs.
002- OK: sleep_10000_micro
     -------------
     Verifying sleep_20000_micro...
005+ Failed sleep_20000_micro. Expected: 20000 microsecs. Actual: 25018 microsecs.
005- OK: sleep_20000_micro
     -------------
     Verifying sleep_50000_micro...
     OK: sleep_50000_micro
--

But this is not related to MacOS only - reproducing on Linux as well, I added #74 to cover this issue as well

andypost commented 1 year ago

FYI still randomly getting error on s390x (guess it depends on server load)

TEST 5/13 [tests/xhprof_005.phpt]
========DIFF========
     Verifying sleep_10000_micro...
002+ Failed sleep_10000_micro. Expected: 10000 microsecs. Actual: 15194 microsecs.
002- OK: sleep_10000_micro
     -------------
     Verifying sleep_20000_micro...
     OK: sleep_20000_micro
--
========DONE========
FAIL XHProf: Timer Tests
longxinH commented 1 year ago

I'm very sorry, after reinstalling the test machine, I lost the s390x environment, and now I'm reinstalling the s390x environment

longxinH commented 1 year ago

@andypost Can you provide information about s390x? Because I am on the test machine, there is no reproduction

andypost commented 1 year ago

@longxinH I'm using alpinelinux/alpine-gitlab-ci:latest-s390x docker image

longxinH commented 1 year ago

@andypost I executed 7.4.18 8.0.22 8.2.1 respectively in the alpinelinux/alpine-gitlab-ci:latest-s390x image and no errors occurred

7.4.18

PHP : /usr/local/php-7.4.18/bin/php PHP_SAPI : cli PHP_VERSION : 7.4.18 ZEND_VERSION: 3.4.0 PHP_OS : Linux - Linux c0d4a86f443b 5.15.49-linuxkit #1 SMP Tue Sep 13 07:51:46 UTC 2022 s390x INI actual : /usr/local/php-ext/extension/tmp-php.ini More .INIs :

PHP : /usr/local/php-7.4.18/bin/phpdbg PHP_SAPI : phpdbg PHP_VERSION : 7.4.18 ZEND_VERSION: 3.4.0 PHP_OS : Linux - Linux c0d4a86f443b 5.15.49-linuxkit #1 SMP Tue Sep 13 07:51:46 UTC 2022 s390x INI actual : /usr/local/php-ext/extension/tmp-php.ini More .INIs :

CWD : /usr/local/php-ext/extension Extra dirs : VALGRIND : Not used

TIME START 2023-01-12 08:07:19

PASS XHProf: Basic Profiling Test Author: Kannan [tests/xhprof_001.phpt] PASS XHProf: Test (direct and indirect) recursive function calls. Author: Kannan [tests/xhprof_002.phpt] PASS XHProf: Test Class Methods, Constructors, Destructors. Author: Kannan [tests/xhprof_003.phpt] PASS XHProf: Test Include File (load/run_init operations) Author: Kannan [tests/xhprof_004.phpt] PASS XHProf: Timer Tests005.phpt] Author: Kannan [tests/xhprof_005.phpt] PASS XHProf: Basic Sampling Test] Author: mpal [tests/xhprof_006.phpt] PASS XHProf: Test excluding call_user_func and similar functions Author: mpal [tests/xhprof_007.phpt] PASS XHProf: Sampling Mode Testt] Author: kannan [tests/xhprof_008.phpt] PASS XHProf: PHP 5.5 crash in hp_execute_internal Author: epriestley [tests/xhprof_009.phpt] PASS XHProf: Crash with auto_append_file Author: epriestley [tests/xhprof_010.phpt] PASS XHProf: Crash with auto_prepend_file Author: epriestley [tests/xhprof_011.phpt] SKIP XHProf: Test Curl Additional Info Author: longxinhui [tests/xhprof_012.phpt] PASS XHProf: Test Sampling Interval Author: longxinhui [tests/xhprof_013.phpt]

TIME END 2023-01-12 08:07:27

8.0.22

PHP : /usr/local/php-8.0.22/bin/php PHP_SAPI : cli PHP_VERSION : 8.0.22 ZEND_VERSION: 4.0.22 PHP_OS : Linux - Linux c0d4a86f443b 5.15.49-linuxkit #1 SMP Tue Sep 13 07:51:46 UTC 2022 s390x INI actual : /usr/local/php-ext/extension/tmp-php.ini More .INIs :

PHP : /usr/local/php-8.0.22/bin/phpdbg PHP_SAPI : phpdbg PHP_VERSION : 8.0.22 ZEND_VERSION: 4.0.22 PHP_OS : Linux - Linux c0d4a86f443b 5.15.49-linuxkit #1 SMP Tue Sep 13 07:51:46 UTC 2022 s390x INI actual : /usr/local/php-ext/extension/tmp-php.ini More .INIs :

CWD : /usr/local/php-ext/extension Extra dirs : VALGRIND : Not used

TIME START 2023-01-12 08:09:30

PASS XHProf: Basic Profiling Test Author: Kannan [tests/xhprof_001.phpt] PASS XHProf: Test (direct and indirect) recursive function calls. Author: Kannan [tests/xhprof_002.phpt] PASS XHProf: Test Class Methods, Constructors, Destructors. Author: Kannan [tests/xhprof_003.phpt] PASS XHProf: Test Include File (load/run_init operations) Author: Kannan [tests/xhprof_004.phpt] PASS XHProf: Timer Tests005.phpt] Author: Kannan [tests/xhprof_005.phpt] PASS XHProf: Basic Sampling Test] Author: mpal [tests/xhprof_006.phpt] PASS XHProf: Test excluding call_user_func and similar functions Author: mpal [tests/xhprof_007.phpt] PASS XHProf: Sampling Mode Testt] Author: kannan [tests/xhprof_008.phpt] PASS XHProf: PHP 5.5 crash in hp_execute_internal Author: epriestley [tests/xhprof_009.phpt] PASS XHProf: Crash with auto_append_file Author: epriestley [tests/xhprof_010.phpt] PASS XHProf: Crash with auto_prepend_file Author: epriestley [tests/xhprof_011.phpt] SKIP XHProf: Test Curl Additional Info Author: longxinhui [tests/xhprof_012.phpt] PASS XHProf: Test Sampling Interval Author: longxinhui [tests/xhprof_013.phpt]

TIME END 2023-01-12 08:09:38

8.2.1

PHP : /usr/local/php-8.2.1/bin/php PHP_SAPI : cli PHP_VERSION : 8.2.1 ZEND_VERSION: 4.2.1 PHP_OS : Linux - Linux c0d4a86f443b 5.15.49-linuxkit #1 SMP Tue Sep 13 07:51:46 UTC 2022 s390x INI actual : /usr/local/php-ext/extension/tmp-php.ini More .INIs :

PHP : /usr/local/php-8.2.1/bin/php-cgi PHP_SAPI : cgi-fcgi PHP_VERSION : 8.2.1 ZEND_VERSION: 4.2.1 PHP_OS : Linux - Linux c0d4a86f443b 5.15.49-linuxkit #1 SMP Tue Sep 13 07:51:46 UTC 2022 s390x INI actual : /usr/local/php-ext/extension/tmp-php.ini More .INIs :

PHP : /usr/local/php-8.2.1/bin/phpdbg PHP_SAPI : phpdbg PHP_VERSION : 8.2.1 ZEND_VERSION: 4.2.1 PHP_OS : Linux - Linux c0d4a86f443b 5.15.49-linuxkit #1 SMP Tue Sep 13 07:51:46 UTC 2022 s390x INI actual : /usr/local/php-ext/extension/tmp-php.ini More .INIs :

CWD : /usr/local/php-ext/extension Extra dirs : VALGRIND : Not used

TIME START 2023-01-12 08:15:18

PASS XHProf: Basic Profiling Test Author: Kannan [tests/xhprof_001.phpt] PASS XHProf: Test (direct and indirect) recursive function calls. Author: Kannan [tests/xhprof_002.phpt] PASS XHProf: Test Class Methods, Constructors, Destructors. Author: Kannan [tests/xhprof_003.phpt] PASS XHProf: Test Include File (load/run_init operations) Author: Kannan [tests/xhprof_004.phpt] PASS XHProf: Timer Tests005.phpt] Author: Kannan [tests/xhprof_005.phpt] PASS XHProf: Basic Sampling Test] Author: mpal [tests/xhprof_006.phpt] PASS XHProf: Test excluding call_user_func and similar functions Author: mpal [tests/xhprof_007.phpt] PASS XHProf: Sampling Mode Testt] Author: kannan [tests/xhprof_008.phpt] PASS XHProf: PHP 5.5 crash in hp_execute_internal Author: epriestley [tests/xhprof_009.phpt] PASS XHProf: Crash with auto_append_file Author: epriestley [tests/xhprof_010.phpt] PASS XHProf: Crash with auto_prepend_file Author: epriestley [tests/xhprof_011.phpt] SKIP XHProf: Test Curl Additional Info Author: longxinhui [tests/xhprof_012.phpt] PASS XHProf: Test Sampling Interval Author: longxinhui [tests/xhprof_013.phpt]

TIME END 2023-01-12 08:15:26

andypost commented 1 year ago

Thank you! Yes, exactly - it passes most of time but sometimes fails both in CI and builder (using real hardware) that's why I guessed that's RTC on s390x can vary or maybe process gets sleep or no processor time quant