Skip to content

Instantly share code, notes, and snippets.

@shqking
Last active October 26, 2021 01:55
Show Gist options
  • Save shqking/1e2c65b188b627671ebb8fd6e8bc493d to your computer and use it in GitHub Desktop.
Save shqking/1e2c65b188b627671ebb8fd6e8bc493d to your computer and use it in GitHub Desktop.
tracing-JIT-laravel

Tracing JIT issue on laravel benchmark.

  1. Both JIT/arm64 and JIT/x86 are affected.
  2. only CALL+noGRV is affected. JIT has three configurations, HYBRID, CALL with global register variabels feature(CALL+GRV for short) and CALL+noGRV. In my local test, only CALL+noGRV has this issue, i.e. --disable-gcc-global-regs should be passed.

Reproduce in laravel:

php vendor/bin/phpunit --group default

Error log(part of):

............................................................. 1952 / 6538 ( 29%)
............................................................. 2013 / 6538 ( 30%)
............................................................. 2074 / 6538 ( 31%)
............................................................. 2135 / 6538 ( 32%)
............................................................. 2196 / 6538 ( 33%)
EEEE.EEEE................................EE.................. 2257 / 6538 ( 34%)
.........E........E......EEEEEEEEEEEEEEE..................... 2318 / 6538 ( 35%)
............................................................. 2379 / 6538 ( 36%)
.....................
Deprecated: Return type of League\Flysystem\FileAttributes::offsetGet($offset) should either be compatible with ArrayAccess::offsetGet(mixed $offset): mixed, or the #[\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /tmp/php-oss/laravel/vendor/league/flysystem/src/ProxyArrayAccessToProperties.php on line 36
........................................ 2440 / 6538 ( 37%)
...............................php: /tmp/php-src/Zend/zend_execute.h:302: zend_vm_stack_free_call_frame_ex: Assertion `call == (zend_execute_data*)(((zval*)((executor_globals.vm_stack))) + (((((sizeof(struct _zend_vm_stack)) + 8 - 1) & ~(8 - 1)) + (((sizeof(zval)) + 8 - 1) & ~(8 - 1)) - 1) / (((sizeof(zval)) + 8 - 1) & ~(8 - 1))))' failed.
php: /tmp/php-src/Zend/zend_execute.h:302: zend_vm_stack_free_call_frame_ex: Assertion `call == (zend_execute_data*)(((zval*)((executor_globals.vm_stack))) + (((((sizeof(struct _zend_vm_stack)) + 8 - 1) & ~(8 - 1)) + (((sizeof(zval)) + 8 - 1) & ~(8 - 1)) - 1) / (((sizeof(zval)) + 8 - 1) & ~(8 - 1))))' failed.
php: /tmp/php-src/Zend/zend_execute.h:302: zend_vm_stack_free_call_frame_ex: Assertion `call == (zend_execute_data*)(((zval*)((executor_globals.vm_stack))) + (((((sizeof(struct _zend_vm_stack)) + 8 - 1) & ~(8 - 1)) + (((sizeof(zval)) + 8 - 1) & ~(8 - 1)) - 1) / (((sizeof(zval)) + 8 - 1) & ~(8 - 1))))' failed.
@dstogov
Copy link

dstogov commented Oct 20, 2021

@shqking Unfortunately, I'm not able to reproduce this. Please provide the backtrace and values of call and EG(vm_stack))

@shqking
Copy link
Author

shqking commented Oct 20, 2021

@shqking Unfortunately, I'm not able to reproduce this. Please provide the backtrace and values of call and EG(vm_stack))

In my local test environment, this error only appeared in some CPUs. Yes. I'm not whether you can reproduce it in your environment.

  1. Not sure if you are using NTS or ZTS? Could you please try the other mode?
  2. Could you also try your ARM environment(i.e. the cross-compile one) as well?

I failed to get the backtrace.
As I see it, multiple processes are used to run all the test cases, and I failed to attach the child process in time.
I add one printf in php src code to dump the call and EG(vm_stack) info.

diff --git a/Zend/zend_execute.h b/Zend/zend_execute.h
index 278afc9c1..8a8103803 100644
--- a/Zend/zend_execute.h
+++ b/Zend/zend_execute.h
@@ -299,6 +299,9 @@ static zend_always_inline void zend_vm_stack_free_call_frame_ex(uint32_t call_in
                zend_vm_stack p = EG(vm_stack);
                zend_vm_stack prev = p->prev;

+               if (call != (zend_execute_data*)ZEND_VM_STACK_ELEMENTS(EG(vm_stack))) {
+                       printf("bad here. call %p, %p\n\n", call, (zend_execute_data*)ZEND_VM_STACK_ELEMENTS(EG(vm_stack)));
+               }
                ZEND_ASSERT(call == (zend_execute_data*)ZEND_VM_STACK_ELEMENTS(EG(vm_stack)));
                EG(vm_stack_top) = prev->top;
                EG(vm_stack_end) = prev->end;

gdb log(part of):

[Detaching after fork from child process 429]
[Detaching after fork from child process 430]
[Detaching after fork from child process 431]
bad here. call 0xffffad0073f0, 0xffffad006020

php: /tmp/php-src/Zend/zend_execute.h:305: zend_vm_stack_free_call_frame_ex: Assertion `call == (zend_execute_data*)(((zval*)((executor_globals.vm_stack))) + (((((sizeof(struct _zend_vm_stack)) + 8 - 1) & ~(8 - 1)) + (((sizeof(zval)) + 8 - 1) & ~(8 - 1)) - 1) / (((sizeof(zval)) + 8 - 1) & ~(8 - 1))))' failed.
[Detaching after fork from child process 432]
bad here. call 0xffffad0073f0, 0xffffad006020

php: /tmp/php-src/Zend/zend_execute.h:305: zend_vm_stack_free_call_frame_ex: Assertion `call == (zend_execute_data*)(((zval*)((executor_globals.vm_stack))) + (((((sizeof(struct _zend_vm_stack)) + 8 - 1) & ~(8 - 1)) + (((sizeof(zval)) + 8 - 1) & ~(8 - 1)) - 1) / (((sizeof(zval)) + 8 - 1) & ~(8 - 1))))' failed.
[Detaching after fork from child process 433]
bad here. call 0xffffad0073f0, 0xffffad006020

@shqking
Copy link
Author

shqking commented Oct 20, 2021

@dstogov
I used this a bit ugly way to attach the child process and print the backtrace.

Hack to php src code.

# git diff Zend/zend_execute.h
diff --git a/Zend/zend_execute.h b/Zend/zend_execute.h
index 278afc9c1..391c6bb74 100644
--- a/Zend/zend_execute.h
+++ b/Zend/zend_execute.h
@@ -25,6 +25,7 @@
 #include "zend_hash.h"
 #include "zend_operators.h"
 #include "zend_variables.h"
+#include "unistd.h"

 BEGIN_EXTERN_C()
 struct _zend_fcall_info;
@@ -299,6 +300,10 @@ static zend_always_inline void zend_vm_stack_free_call_frame_ex(uint32_t call_in
                zend_vm_stack p = EG(vm_stack);
                zend_vm_stack prev = p->prev;

+               if (call != (zend_execute_data*)ZEND_VM_STACK_ELEMENTS(EG(vm_stack))) {
+                       printf("bad here.pid:%d, call %p, %p\n\n", getpid(), call, (zend_execute_data*)ZEND_VM_STACK_ELEMENTS(EG(vm_stack)));
+                       sleep(60);
+               }
                ZEND_ASSERT(call == (zend_execute_data*)ZEND_VM_STACK_ELEMENTS(EG(vm_stack)));
                EG(vm_stack_top) = prev->top;
                EG(vm_stack_end) = prev->end;

Part of the back trace info.

#0  0x0000ffffb5894700 in clock_nanosleep () from /usr/lib/aarch64-linux-gnu/libc.so.6
#1  0x0000ffffb589a134 in nanosleep () from /usr/lib/aarch64-linux-gnu/libc.so.6
#2  0x0000ffffb589a010 in sleep () from /usr/lib/aarch64-linux-gnu/libc.so.6
#3  0x0000aaaaac21fd84 in zend_vm_stack_free_call_frame_ex (call_info=2918504448, call=0xffffad0073f0) at /tmp/php-src/Zend/zend_execute.h:305
#4  0x0000aaaaac2200a8 in zend_vm_stack_free_call_frame (call=0xffffad0073f0) at /tmp/php-src/Zend/zend_execute.h:321
#5  0x0000aaaaac2292a0 in zend_call_function (fci=0xfffffffd0d20, fci_cache=0xfffffffd0ce0) at /tmp/php-src/Zend/zend_execute_API.c:955
#6  0x0000aaaaac229804 in zend_call_known_function (fn=0xffff9e723e50, object=0xffff8ed9f150, called_scope=0xffff9e804f20, retval_ptr=0xffffad0073c0, param_count=1,
    params=0xfffffffd0e90, named_params=0x0) at /tmp/php-src/Zend/zend_execute_API.c:992
#7  0x0000aaaaac51dbb4 in zend_call_known_instance_method (fn=0xffff9e723e50, object=0xffff8ed9f150, retval_ptr=0xffffad0073c0, param_count=1, params=0xfffffffd0e90)
    at /tmp/php-src/Zend/zend_API.h:666
#8  0x0000aaaaac51dc28 in zend_call_known_instance_method_with_1_params (fn=0xffff9e723e50, object=0xffff8ed9f150, retval_ptr=0xffffad0073c0, param=0xfffffffd0e90)
    at /tmp/php-src/Zend/zend_API.h:678
#9  0x0000aaaaac51eed0 in zend_std_call_getter (zobj=0xffff8ed9f150, prop_name=0xffff9a322b98, retval=0xffffad0073c0) at /tmp/php-src/Zend/zend_object_handlers.c:192
#10 0x0000aaaaac522928 in zend_std_read_property (zobj=0xffff8ed9f150, name=0xffff9a322b98, type=0, cache_slot=0xffff6cf1aba0, rv=0xffffad0073c0)
    at /tmp/php-src/Zend/zend_object_handlers.c:681
#11 0x0000aaaaac44d610 in ZEND_FETCH_OBJ_R_SPEC_CV_CONST_HANDLER (execute_data=0xffffad007360) at /tmp/php-src/Zend/zend_vm_execute.h:40086
#12 0x0000aaaaac30643c in execute_ex (ex=0xffffad007400) at /tmp/php-src/Zend/zend_vm_execute.h:455
#13 0x0000aaaaac22883c in zend_call_function (fci=0xfffffffd14e0, fci_cache=0xfffffffd14a0) at /tmp/php-src/Zend/zend_execute_API.c:903
#14 0x0000aaaaac229804 in zend_call_known_function (fn=0xffff9e723e50, object=0xffff8ff935b0, called_scope=0xffff9e804f20, retval_ptr=0xffffad0073d0, param_count=1,
    params=0xfffffffd1650, named_params=0x0) at /tmp/php-src/Zend/zend_execute_API.c:992
#15 0x0000aaaaac51dbb4 in zend_call_known_instance_method (fn=0xffff9e723e50, object=0xffff8ff935b0, retval_ptr=0xffffad0073d0, param_count=1, params=0xfffffffd1650)
    at /tmp/php-src/Zend/zend_API.h:666
#16 0x0000aaaaac51dc28 in zend_call_known_instance_method_with_1_params (fn=0xffff9e723e50, object=0xffff8ff935b0, retval_ptr=0xffffad0073d0, param=0xfffffffd1650)
    at /tmp/php-src/Zend/zend_API.h:678
#17 0x0000aaaaac51eed0 in zend_std_call_getter (zobj=0xffff8ff935b0, prop_name=0xffff9a36eed0, retval=0xffffad0073d0) at /tmp/php-src/Zend/zend_object_handlers.c:192
#18 0x0000aaaaac522928 in zend_std_read_property (zobj=0xffff8ff935b0, name=0xffff9a36eed0, type=0, cache_slot=0xffff6c878a10, rv=0xffffad0073d0)
    at /tmp/php-src/Zend/zend_object_handlers.c:681
#19 0x0000aaaaac44d610 in ZEND_FETCH_OBJ_R_SPEC_CV_CONST_HANDLER (execute_data=0xffffad007360) at /tmp/php-src/Zend/zend_vm_execute.h:40086
#20 0x0000aaaaac30643c in execute_ex (ex=0xffffad007400) at /tmp/php-src/Zend/zend_vm_execute.h:455
#21 0x0000aaaaac22883c in zend_call_function (fci=0xfffffffd1ca0, fci_cache=0xfffffffd1c60) at /tmp/php-src/Zend/zend_execute_API.c:903
#22 0x0000aaaaac229804 in zend_call_known_function (fn=0xffff9e723e50, object=0xffff9218f460, called_scope=0xffff9e804f20, retval_ptr=0xffffad0073d0, param_count=1,
    params=0xfffffffd1e10, named_params=0x0) at /tmp/php-src/Zend/zend_execute_API.c:992
#23 0x0000aaaaac51dbb4 in zend_call_known_instance_method (fn=0xffff9e723e50, object=0xffff9218f460, retval_ptr=0xffffad0073d0, param_count=1, params=0xfffffffd1e10)
    at /tmp/php-src/Zend/zend_API.h:666
#24 0x0000aaaaac51dc28 in zend_call_known_instance_method_with_1_params (fn=0xffff9e723e50, object=0xffff9218f460, retval_ptr=0xffffad0073d0, param=0xfffffffd1e10)
    at /tmp/php-src/Zend/zend_API.h:678
#25 0x0000aaaaac51eed0 in zend_std_call_getter (zobj=0xffff9218f460, prop_name=0xffff9a36eed0, retval=0xffffad0073d0) at /tmp/php-src/Zend/zend_object_handlers.c:192
#26 0x0000aaaaac522928 in zend_std_read_property (zobj=0xffff9218f460, name=0xffff9a36eed0, type=0, cache_slot=0xffff6c878910, rv=0xffffad0073d0)
    at /tmp/php-src/Zend/zend_object_handlers.c:681
#27 0x0000aaaaac44d610 in ZEND_FETCH_OBJ_R_SPEC_CV_CONST_HANDLER (execute_data=0xffffad007360) at /tmp/php-src/Zend/zend_vm_execute.h:40086
#28 0x0000aaaaac30643c in execute_ex (ex=0xffffad007400) at /tmp/php-src/Zend/zend_vm_execute.h:455
#29 0x0000aaaaac22883c in zend_call_function (fci=0xfffffffd2460, fci_cache=0xfffffffd2420) at /tmp/php-src/Zend/zend_execute_API.c:903
#30 0x0000aaaaac229804 in zend_call_known_function (fn=0xffff9e723e50, object=0xffff925ec3f0, called_scope=0xffff9e804f20, retval_ptr=0xffffad0073d0, param_count=1,
    params=0xfffffffd25d0, named_params=0x0) at /tmp/php-src/Zend/zend_execute_API.c:992
#31 0x0000aaaaac51dbb4 in zend_call_known_instance_method (fn=0xffff9e723e50, object=0xffff925ec3f0, retval_ptr=0xffffad0073d0, param_count=1, params=0xfffffffd25d0)
    at /tmp/php-src/Zend/zend_API.h:666
#32 0x0000aaaaac51dc28 in zend_call_known_instance_method_with_1_params (fn=0xffff9e723e50, object=0xffff925ec3f0, retval_ptr=0xffffad0073d0, param=0xfffffffd25d0)
    at /tmp/php-src/Zend/zend_API.h:678
#33 0x0000aaaaac51eed0 in zend_std_call_getter (zobj=0xffff925ec3f0, prop_name=0xffff9a36eed0, retval=0xffffad0073d0) at /tmp/php-src/Zend/zend_object_handlers.c:192
#34 0x0000aaaaac522928 in zend_std_read_property (zobj=0xffff925ec3f0, name=0xffff9a36eed0, type=0, cache_slot=0xffff6c878a10, rv=0xffffad0073d0)
    at /tmp/php-src/Zend/zend_object_handlers.c:681
#35 0x0000aaaaac44d610 in ZEND_FETCH_OBJ_R_SPEC_CV_CONST_HANDLER (execute_data=0xffffad007360) at /tmp/php-src/Zend/zend_vm_execute.h:40086
#36 0x0000aaaaac30643c in execute_ex (ex=0xffffad007400) at /tmp/php-src/Zend/zend_vm_execute.h:455
#37 0x0000aaaaac22883c in zend_call_function (fci=0xfffffffd2c20, fci_cache=0xfffffffd2be0) at /tmp/php-src/Zend/zend_execute_API.c:903
#38 0x0000aaaaac229804 in zend_call_known_function (fn=0xffff9e723e50, object=0xffff9218fe00, called_scope=0xffff9e804f20, retval_ptr=0xffffad0073d0, param_count=1,
     named_params=0x0) at /tmp/php-src/Zend/zend_execute_API.c:992
#39 0x0000aaaaac51dbb4 in zend_call_known_instance_method (fn=0xffff9e723e50, object=0xffff9218fe00, retval_ptr=0xffffad0073d0, param_count=1, params=0xfffffffd2d90)
    at /tmp/php-src/Zend/zend_API.h:666
#40 0x0000aaaaac51dc28 in zend_call_known_instance_method_with_1_params (fn=0xffff9e723e50, object=0xffff9218fe00, retval_ptr=0xffffad0073d0, param=0xfffffffd2d90)
    at /tmp/php-src/Zend/zend_API.h:678
#41 0x0000aaaaac51eed0 in zend_std_call_getter (zobj=0xffff9218fe00, prop_name=0xffff9a36eed0, retval=0xffffad0073d0) at /tmp/php-src/Zend/zend_object_handlers.c:192
#42 0x0000aaaaac522928 in zend_std_read_property (zobj=0xffff9218fe00, name=0xffff9a36eed0, type=0, cache_slot=0xffff6c878a10, rv=0xffffad0073d0)
    at /tmp/php-src/Zend/zend_object_handlers.c:681
#43 0x0000aaaaac44d610 in ZEND_FETCH_OBJ_R_SPEC_CV_CONST_HANDLER (execute_data=0xffffad007360) at /tmp/php-src/Zend/zend_vm_execute.h:40086
#44 0x0000aaaaac30643c in execute_ex (ex=0xffffad007400) at /tmp/php-src/Zend/zend_vm_execute.h:455
#45 0x0000aaaaac22883c in zend_call_function (fci=0xfffffffd33e0, fci_cache=0xfffffffd33a0) at /tmp/php-src/Zend/zend_execute_API.c:903
#46 0x0000aaaaac229804 in zend_call_known_function (fn=0xffff9e723e50, object=0xffff922dbe70, called_scope=0xffff9e804f20, retval_ptr=0xffffad0073d0, param_count=1,
    params=0xfffffffd3550, named_params=0x0) at /tmp/php-src/Zend/zend_execute_API.c:992
#47 0x0000aaaaac51dbb4 in zend_call_known_instance_method (fn=0xffff9e723e50, object=0xffff922dbe70, retval_ptr=0xffffad0073d0, param_count=1, params=0xfffffffd3550)
    at /tmp/php-src/Zend/zend_API.h:666
#48 0x0000aaaaac51dc28 in zend_call_known_instance_method_with_1_params (fn=0xffff9e723e50, object=0xffff922dbe70, retval_ptr=0xffffad0073d0, param=0xfffffffd3550)
    at /tmp/php-src/Zend/zend_API.h:678
#49 0x0000aaaaac51eed0 in zend_std_call_getter (zobj=0xffff922dbe70, prop_name=0xffff9a36eed0, retval=0xffffad0073d0) at /tmp/php-src/Zend/zend_object_handlers.c:192
#50 0x0000aaaaac522928 in zend_std_read_property (zobj=0xffff922dbe70, name=0xffff9a36eed0, type=0, cache_slot=0xffff6c878910, rv=0xffffad0073d0)
    at /tmp/php-src/Zend/zend_object_ha#51 0x0000aaaaac44d610 in ZEND_FETCH_OBJ_R_SPEC_CV_CONST_HANDLER (execute_data=0xffffad007360) at /tmp/php-src/Zend/zend_vm_execute.h:40086
#52 0x0000aaaaac30643c in execute_ex (ex=0xffffad007400) at /tmp/php-src/Zend/zend_vm_execute.h:455
#53 0x0000aaaaac22883c in zend_call_function (fci=0xfffffffd3ba0, fci_cache=0xfffffffd3b60) at /tmp/php-src/Zend/zend_execute_API.c:903
#54 0x0000aaaaac229804 in zend_call_known_function (fn=0xffff9e723e50, object=0xffff8f60af50, called_scope=0xffff9e804f20, retval_ptr=0xffffad0073d0, param_count=1,
    params=0xfffffffd3d10, named_params=0x0) at /tmp/php-src/Zend/zend_execute_API.c:992
#55 0x0000aaaaac51dbb4 in zend_call_known_instance_method (fn=0xffff9e723e50, object=0xffff8f60af50, retval_ptr=0xffffad0073d0, param_count=1, params=0xfffffffd3d10)
    at /tmp/php-src/Zend/zend_API.h:666
#56 0x0000aaaaac51dc28 in zend_call_known_instance_method_with_1_params (fn=0xffff9e723e50, object=0xffff8f60af50, retval_ptr=0xffffad0073d0, param=0xfffffffd3d10)
    at /tmp/php-src/Zend/zend_API.h:678
#57 0x0000aaaaac51eed0 in zend_std_call_getter (zobj=0xffff8f60af50, prop_name=0xffff9a36eed0, retval=0xffffad0073d0) at /tmp/php-src/Zend/zend_object_handlers.c:192
#58 0x0000aaaaac522928 in zend_std_read_property (zobj=0xffff8f60af50, name=0xffff9a36eed0, type=0, cache_slot=0xffff6c878910, rv=0xffffad0073d0)
    at /tmp/php-src/Zend/zend_object_handlers.c:681
#59 0x0000aaaaac44d610 in ZEND_FETCH_OBJ_R_SPEC_CV_CONST_HANDLER (execute_data=0xffffad007360) at /tmp/php-src/Zend/zend_vm_execute.h:40086
#60 0x0000aaaaac30643c in execute_ex (ex=0xffffad007460) at /tmp/php-src/Zend/zend_vm_execute.h:455
#61 0x0000aaaaac22883c in zend_call_function (fci=0xfffffffd4360, fci_cache=0xfffffffd4320) at /tmp/php-src/Zend/zend_execute_API.c:903
#62 0x0000aaaaac229804 in zend_call_known_function (fn=0xffff9e723e50, object=0xffff914817e0, called_scope=0xffff9e804f20, retval_ptr=0xffffad007430, param_count=1,
    params=0xfffffffd44d0, named_params=0x0) at /tmp/php-src/Zend/zend_execute_API.c:992
#63 0x0000aaaaac51dbb4 in zend_call_known_instance_method (fn=0xffff9e723e50, object=0xffff914817e0, retval_ptr=0xffffad007430, param_count=1, params=0xfffffffd44d0)
    at /tmp/php-src/Zend/zend_API.h:666
#64 0x0000aaaaac51dc28 in zend_call_known_instance_method_with_1_params (fn=0xffff9e723e50, object=0xffff914817e0, retval_ptr=0xffffad007430, param=0xfffffffd44d0)
    at /tmp/php-src/Zend/zend_API.h:678
#65 0x0000aaaaac51eed0 in zend_std_call_getter (zobj=0xffff914817e0, prop_name=0xffff9a36eed0, retval=0xffffad007430) at /tmp/php-src/Zend/zend_object_handlers.c:192
#66 0x0000aaaaac522928 in zend_std_read_property (zobj=0xffff914817e0, name=0xffff9a36eed0, type=0, cache_slot=0xffff6ca68310, rv=0xffffad007430)
    at /tmp/php-src/Zend/zend_object_handlers.c:681
#67 0x0000aaaaac44d610 in ZEND_FETCH_OBJ_R_SPEC_CV_CONST_HANDLER (execute_data=0xffffad0073d0) at /tmp/php-src/Zend/zend_vm_execute.h:40086
#68 0x0000aaaaac30643c in execute_ex (ex=0xffffad007460) at /tmp/php-src/Zend/zend_vm_execute.h:455
#69 0x0000aaaaac22883c in zend_call_function (fci=0xfffffffd4b20, fci_cache=0xfffffffd4ae0) at /tmp/php-src/Zend/zend_execute_API.c:903
#70 0x0000aaaaac229804 in zend_call_known_function (fn=0xffff9e723e50, object=0xffff90b480e0, called_scope=0xffff9e804f20, retval_ptr=0xffffad007430, param_count=1,
    params=0xfffffffd4c90, named_params=0x0) at /tmp/php-src/Zend/zend_execute_API.c:992
#71 0x0000aaaaac51dbb4 in zend_call_known_instance_method (fn=0xffff9e723e50, object=0xffff90b480e0, retval_ptr=0xffffad007430, param_count=1, params=0xfffffffd4c90)
    at /tmp/php-src/Zend/zend_API.h:666
#72 0x0000aaaaac51dc28 in zend_call_known_instance_method_with_1_params (fn=0xffff9e723e50, object=0xffff90b480e0, retval_ptr=0xffffad007430, param=0xfffffffd4c90)
    at /tmp/php-src/Zend/zend_API.h:678
#73 0x0000aaaaac51eed0 in zend_std_call_getter (zobj=0xffff90b480e0, prop_name=0xffff9a36eed0, retval=0xffffad007430) at /tmp/php-src/Zend/zend_object_handlers.c:192
ndlers.c:681
#74 0x0000aaaaac522928 in zend_std_read_property (zobj=0xffff90b480e0, name=0xffff9a36eed0, type=0, cache_slot=0xffff6ca68310, rv=0xffffad007430)
#75 0x0000aaaaac44d610 in ZEND_FETCH_OBJ_R_SPEC_CV_CONST_HANDLER (execute_data=0xffffad0073d0) at /tmp/php-src/Zend/zend_vm_execute.h:40086
#76 0x0000aaaaac30643c in execute_ex (ex=0xffffad0073f0) at /tmp/php-src/Zend/zend_vm_execute.h:455
#77 0x0000aaaaac22883c in zend_call_function (fci=0xfffffffd52e0, fci_cache=0xfffffffd52a0) at /tmp/php-src/Zend/zend_execute_API.c:903
#78 0x0000aaaaac229804 in zend_call_known_function (fn=0xffff9e723e50, object=0xffff6d1272a0, called_scope=0xffff9e804f20, retval_ptr=0xffffad0073c0, param_count=1,
    params=0xfffffffd5450, named_params=0x0) at /tmp/php-src/Zend/zend_execute_API.c:992
#79 0x0000aaaaac51dbb4 in zend_call_known_instance_method (fn=0xffff9e723e50, object=0xffff6d1272a0, retval_ptr=0xffffad0073c0, param_count=1, params=0xfffffffd5450)
    at /tmp/php-src/Zend/zend_API.h:666
#80 0x0000aaaaac51dc28 in zend_call_known_instance_method_with_1_params (fn=0xffff9e723e50, object=0xffff6d1272a0, retval_ptr=0xffffad0073c0, param=0xfffffffd5450)
    at /tmp/php-src/Zend/zend_API.h:678
#81 0x0000aaaaac51eed0 in zend_std_call_getter (zobj=0xffff6d1272a0, prop_name=0xffff9a36eed0, retval=0xffffad0073c0) at /tmp/php-src/Zend/zend_object_handlers.c:192
#82 0x0000aaaaac522928 in zend_std_read_property (zobj=0xffff6d1272a0, name=0xffff9a36eed0, type=0, cache_slot=0xffff6ca68310, rv=0xffffad0073c0)
    at /tmp/php-src/Zend/zend_object_handlers.c:681
#83 0x0000aaaaac44d610 in ZEND_FETCH_OBJ_R_SPEC_CV_CONST_HANDLER (execute_data=0xffffad007360) at /tmp/php-src/Zend/zend_vm_execute.h:40086
#84 0x0000aaaaac30643c in execute_ex (ex=0xffffad0073f0) at /tmp/php-src/Zend/zend_vm_execute.h:455
#85 0x0000aaaaac22883c in zend_call_function (fci=0xfffffffd5aa0, fci_cache=0xfffffffd5a60) at /tmp/php-src/Zend/zend_execute_API.c:903
#86 0x0000aaaaac229804 in zend_call_known_function (fn=0xffff9e723e50, object=0xffff6d122a10, called_scope=0xffff9e804f20, retval_ptr=0xffffad0073c0, param_count=1,
    params=0xfffffffd5c10, named_params=0x0) at /tmp/php-src/Zend/zend_execute_API.c:992
#87 0x0000aaaaac51dbb4 in zend_call_known_instance_method (fn=0xffff9e723e50, object=0xffff6d122a10, retval_ptr=0xffffad0073c0, param_count=1, params=0xfffffffd5c10)
    at /tmp/php-src/Zend/zend_API.h:666
#88 0x0000aaaaac51dc28 in zend_call_known_instance_method_with_1_params (fn=0xffff9e723e50, object=0xffff6d122a10, retval_ptr=0xffffad0073c0, param=0xfffffffd5c10)
    at /tmp/php-src/Zend/zend_API.h:678
#89 0x0000aaaaac51eed0 in zend_std_call_getter (zobj=0xffff6d122a10, prop_name=0xffff9a36eed0, retval=0xffffad0073c0) at /tmp/php-src/Zend/zend_object_handlers.c:192
#90 0x0000aaaaac522928 in zend_std_read_property (zobj=0xffff6d122a10, name=0xffff9a36eed0, type=0, cache_slot=0xffff6ca68310, rv=0xffffad0073c0)
    at /tmp/php-src/Zend/zend_object_handlers.c:681
#91 0x0000aaaaac44d610 in ZEND_FETCH_OBJ_R_SPEC_CV_CONST_HANDLER (execute_data=0xffffad007360) at /tmp/php-src/Zend/zend_vm_execute.h:40086
#92 0x0000aaaaac30643c in execute_ex (ex=0xffffad007470) at /tmp/php-src/Zend/zend_vm_execute.h:455
#93 0x0000aaaaac22883c in zend_call_function (fci=0xfffffffd6260, fci_cache=0xfffffffd6220) at /tmp/php-src/Zend/zend_execute_API.c:903
#94 0x0000aaaaac229804 in zend_call_known_function (fn=0xffff9e723e50, object=0xffff6d122700, called_scope=0xffff9e804f20, retval_ptr=0xffffad007440, param_count=1,
    params=0xfffffffd63d0, named_params=0x0) at /tmp/php-src/Zend/zend_execute_API.c:992
#95 0x0000aaaaac51dbb4 in zend_call_known_instance_method (fn=0xffff9e723e50, object=0xffff6d122700, retval_ptr=0xffffad007440, param_count=1, params=0xfffffffd63d0)
    at /tmp/php-src/Zend/zend_API.h:666
#96 0x0000aaaaac51dc28 in zend_call_known_instance_method_with_1_params (fn=0xffff9e723e50, object=0xffff6d122700, retval_ptr=0xffffad007440, param=0xfffffffd63d0)
    at /tmp/php-src/Zend/zend_API.h:678
#97 0x0000aaaaac51eed0 in zend_std_call_getter (zobj=0xffff6d122700, prop_name=0xffff9a36eed0, retval=0xffffad007440) at /tmp/php-src/Zend/zend_object_handlers.c:192
#98 0x0000aaaaac522928 in zend_std_read_property (zobj=0xffff6d122700, name=0xffff9a36eed0, type=0, cache_slot=0xffff6c878a10, rv=0xffffad007440)
    at /tmp/php-src/Zend/zend_object_handlers.c:681
#99 0x0000aaaaac44d610 in ZEND_FETCH_OBJ_R_SPEC_CV_CONST_HANDLER (execute_data=0xffffad0073d0) at /tmp/php-src/Zend/zend_vm_execute.h:40086
#100 0x0000aaaaac30643c in execute_ex (ex=0xffffad007470) at /tmp/php-src/Zend/zend_vm_execute.h:455
#101 0x0000aaaaac22883c in zend_call_function (fci=0xfffffffd6a20, fci_cache=0xfffffffd69e0) at /tmp/php-src/Zend/zend_execute_API.c:903
#102 0x0000aaaaac229804 in zend_call_known_function (fn=0xffff9e723e50, object=0xffff6d157770, called_scope=0xffff9e804f20, retval_ptr=0xffffad007440, param_count=1,
    params=0xfffffffd6b90, named_params=0x0) at /tmp/php-src/Zend/zend_execute_API.c:992
#103 0x0000aaaaac51dbb4 in zend_call_known_instance_method (fn=0xffff9e723e50, object=0xffff6d157770, retval_ptr=0xffffad007440, param_count=1, params=0xfffffffd6b90)
    at /tmp/php-src/Zend/zend_API.h:666
#104 0x0000aaaaac51dc28 in zend_call_known_instance_method_with_1_params (fn=0xffff9e723e50, object=0xffff6d157770, retval_ptr=0xffffad007440, param=0xfffffffd6b90)
    at /tmp/php-src/Zend/zend_API.h:678
#105 0x0000aaaaac51eed0 in zend_std_call_getter (zobj=0xffff6d157770, prop_name=0xffff9a36eed0, retval=0xffffad007440) at /tmp/php-src/Zend/zend_object_handlers.c:192
#106 0x0000aaaaac522928 in zend_std_read_property (zobj=0xffff6d157770, name=0xffff9a36eed0, type=0, cache_slot=0xffff6c878a10, rv=0xffffad007440)
    at /tmp/php-src/Zend/zend_object_handlers.c:681
#107 0x0000aaaaac44d610 in ZEND_FETCH_OBJ_R_SPEC_CV_CONST_HANDLER (execute_data=0xffffad0073d0) at /tmp/php-src/Zend/zend_vm_execute.h:40086
#108 0x0000aaaaac30643c in execute_ex (ex=0xffffad007470) at /tmp/php-src/Zend/zend_vm_execute.h:455
#109 0x0000aaaaac22883c in zend_call_function (fci=0xfffffffd71e0, fci_cache=0xfffffffd71a0) at /tmp/php-src/Zend/zend_execute_API.c:903
#110 0x0000aaaaac229804 in zend_call_known_function (fn=0xffff9e723e50, object=0xffff6d122000, called_scope=0xffff9e804f20, retval_ptr=0xffffad007440, param_count=1,
    params=0xfffffffd7350, named_params=0x0) at /tmp/php-src/Zend/zend_execute_API.c:992

...


#711 0x0000aaaaac51dbb4 in zend_call_known_instance_method (fn=0xffff9e723e50, object=0xffff8ed3f3f0, retval_ptr=0xffffad0074f0, param_count=1, params=0xffffffffab10)
    at /tmp/php-src/Zend/zend_API.h:666
#712 0x0000aaaaac51dc28 in zend_call_known_instance_method_with_1_params (fn=0xffff9e723e50, object=0xffff8ed3f3f0, retval_ptr=0xffffad0074f0, param=0xffffffffab10)
    at /tmp/php-src/Zend/zend_API.h:678
#713 0x0000aaaaac51eed0 in zend_std_call_getter (zobj=0xffff8ed3f3f0, prop_name=0xffff9a322b98, retval=0xffffad0074f0) at /tmp/php-src/Zend/zend_object_handlers.c:192
#714 0x0000aaaaac522928 in zend_std_read_property (zobj=0xffff8ed3f3f0, name=0xffff9a322b98, type=0, cache_slot=0xffff732fb150, rv=0xffffad0074f0)
    at /tmp/php-src/Zend/zend_object_handlers.c:681
#715 0x0000aaaaac44d610 in ZEND_FETCH_OBJ_R_SPEC_CV_CONST_HANDLER (execute_data=0xffffad007490) at /tmp/php-src/Zend/zend_vm_execute.h:40086
#716 0x0000aaaaac30643c in execute_ex (ex=0xffffad007520) at /tmp/php-src/Zend/zend_vm_execute.h:455
#717 0x0000aaaaac22883c in zend_call_function (fci=0xffffffffb160, fci_cache=0xffffffffb120) at /tmp/php-src/Zend/zend_execute_API.c:903
#718 0x0000aaaaac229804 in zend_call_known_function (fn=0xffff9e723e50, object=0xffff8ed661c0, called_scope=0xffff9e804f20, retval_ptr=0xffffad0074f0, param_count=1,
    params=0xffffffffb2d0, named_params=0x0) at /tmp/php-src/Zend/zend_execute_API.c:992
#719 0x0000aaaaac51dbb4 in zend_call_known_instance_method (fn=0xffff9e723e50, object=0xffff8ed661c0, retval_ptr=0xffffad0074f0, param_count=1, params=0xffffffffb2d0)
    at /tmp/php-src/Zend/zend_API.h:666
#720 0x0000aaaaac51dc28 in zend_call_known_instance_method_with_1_params (fn=0xffff9e723e50, object=0xffff8ed661c0, retval_ptr=0xffffad0074f0, param=0xffffffffb2d0)
    at /tmp/php-src/Zend/zend_API.h:678
#721 0x0000aaaaac51eed0 in zend_std_call_getter (zobj=0xffff8ed661c0, prop_name=0xffff9a322b98, retval=0xffffad0074f0) at /tmp/php-src/Zend/zend_object_handlers.c:192
#722 0x0000aaaaac522928 in zend_std_read_property (zobj=0xffff8ed661c0, name=0xffff9a322b98, type=0, cache_slot=0xffff732fb150, rv=0xffffad0074f0)
    at /tmp/php-src/Zend/zend_object_handlers.c:681
#723 0x0000aaaaac44d610 in ZEND_FETCH_OBJ_R_SPEC_CV_CONST_HANDLER (execute_data=0xffffad007490) at /tmp/php-src/Zend/zend_vm_execute.h:40086
#724 0x0000aaaaac30643c in execute_ex (ex=0xffffad006020) at /tmp/php-src/Zend/zend_vm_execute.h:455
#725 0x0000aaaaac306804 in zend_execute (op_array=0xffffad04f640, return_value=0x0) at /tmp/php-src/Zend/zend_vm_execute.h:510

#726 0x0000aaaaac26b5a4 in zend_execute_scripts (type=8, retval=0x0, file_count=3) at /tmp/php-src/Zend/zend.c:1744
#727 0x0000aaaaac0d2990 in php_execute_script (primary_file=0xffffffffe000) at /tmp/php-src/main/main.c:2534
#728 0x0000aaaaac6be9d4 in do_cli (argc=4, argv=0xffffaed00d10) at /tmp/php-src/sapi/cli/php_cli.c:965
#729 0x0000aaaaac6c0cbc in main (argc=4, argv=0xffffaed00d10) at /tmp/php-src/sapi/cli/php_cli.c:1367

@dstogov
Copy link

dstogov commented Oct 20, 2021

The backtrace shows an incorrect recursive call of magic __get() method.
I suppose we should have a error in a trace for that method code, that prevents proper return from execute_ex() and continue the following execution in a wrong execute_ex() context.
I have no idea how to debug this, without a small reproduction case. Try to understand what __get() method is involoved...

(gdb) pring (char*)excutor_globals.current_execute_data[.prev_execute_data].func_op_array.filename.val 
(gdb) pring excutor_globals.current_execute_data[.prev_execute_data].opline.lineno 

check the PHP code of the method, and native code for traces generated for it (something must be wrong with RETURN or side_exit handling)

@shqking
Copy link
Author

shqking commented Oct 21, 2021

The backtrace shows an incorrect recursive call of magic __get() method. I suppose we should have a error in a trace for that method code, that prevents proper return from execute_ex() and continue the following execution in a wrong execute_ex() context. I have no idea how to debug this, without a small reproduction case. Try to understand what __get() method is involoved...

(gdb) pring (char*)excutor_globals.current_execute_data[.prev_execute_data].func_op_array.filename.val 
(gdb) pring excutor_globals.current_execute_data[.prev_execute_data].opline.lineno 

check the PHP code of the method, and native code for traces generated for it (something must be wrong with RETURN or side_exit handling)

Thanks for your hints. It would be very useful to me.

I'm sorry to say I cannot reproduce this error any more(on the same machine with the same PHP src code commit and laravel commit). I'm not sure if the environment changed.

But another fatal error (in test group integration) occurred now. Again, only tracing JIT (both arm64 and x86) with CALL+noGRV is affected.

It's interesting that different error logs would be emitted. Message 1 would be emitted when running command 1. And message 2 or 3 would be emitted by chance when running command 2.

I suspect this error is similar to the previous one yesterday. As you commented, there might be something wrong with the return/exit handling and an amount of memory is consumed, leading to different overflow behaviors afterwards.

Note that if I specified the php test file, i.e. tests/Database/DatabaseConnectionTest.php for message 1, tests/Integration/Foundation/FoundationServiceProvidersTest.php for message 2 andtests/Integration/Cookie/CookieTest.php for mesage 3, this memory error didn't appear. That's why I suspect the memory is consumed hugely by prior buggy test case, but overflowed afterwards.

I will continue to debug it today.

command 1: php vendor/bin/phpunit --debug 
command 2: php vendor/bin/phpunit --group integration --debug

Message 1:

Test 'Illuminate\Tests\Database\DatabaseConnectionTest::testRunMethodRetriesOnFailure' started
php: /tmp/php-src/Zend/zend_gc.c:647: gc_possible_root: Assertion `zval_gc_type((ref)->gc.u.type_info) == 7 || zval_gc_type((ref)->gc.u.type_info) == 8' failed.
Aborted

Message 2:

Test 'Illuminate\Tests\Integration\Foundation\FoundationServiceProvidersTest::it_can_boot_service_provider_registered_from_another_service_provider' started
AddressSanitizer:DEADLYSIGNAL
=================================================================
==20224==ERROR: AddressSanitizer: stack-overflow on address 0xfffff3fc3b30 (pc 0xffffaad300c4 bp 0xfffff3fc4400 sp 0xfffff3fc3b30 T0)
    #0 0xffffaad300c0  (/usr/lib/aarch64-linux-gnu/libasan.so.5+0xbf0c0)
    #1 0xaaaace00c9f8 in zend_hash_str_find_bucket /tmp/php-src/Zend/zend_hash.c:696
    #2 0xaaaace01af78 in zend_hash_str_find /tmp/php-src/Zend/zend_hash.c:2292
    #3 0xaaaace0069f0 in zend_hash_str_find_ptr /tmp/php-src/Zend/zend_hash.h:877
    #4 0xaaaace006fb4 in zend_hash_str_find_ptr_lc /tmp/php-src/Zend/zend_hash.c:95
    #5 0xaaaace2169f4 in zend_call_method /tmp/php-src/Zend/zend_interfaces.c:56
    #6 0xaaaace287090 in zend_std_read_dimension /tmp/php-src/Zend/zend_object_handlers.c:927
    #7 0xaaaace05a34c in zend_fetch_dimension_address_read /tmp/php-src/Zend/zend_execute.c:2530
    #8 0xaaaace05a94c in zend_fetch_dimension_address_read_R_slow /tmp/php-src/Zend/zend_execute.c:2566
    #9 0xaaaace0ee320 in ZEND_FETCH_DIM_R_SPEC_TMPVAR_CONST_HANDLER /tmp/php-src/Zend/zend_vm_execute.h:15381
    #10 0xaaaace1303e0 in ZEND_FETCH_DIM_FUNC_ARG_SPEC_VAR_CONST_HANDLER /tmp/php-src/Zend/zend_vm_execute.h:22776
    #11 0xaaaace06acec in execute_ex /tmp/php-src/Zend/zend_vm_execute.h:455
    #12 0xaaaacdf8d1fc in zend_call_function /tmp/php-src/Zend/zend_execute_API.c:903
    #13 0xaaaacdf8e1c4 in zend_call_known_function /tmp/php-src/Zend/zend_execute_API.c:992
    #14 0xaaaace216b78 in zend_call_method /tmp/php-src/Zend/zend_interfaces.c:82
    #15 0xaaaace287090 in zend_std_read_dimension /tmp/php-src/Zend/zend_object_handlers.c:927
    #16 0xaaaace05a34c in zend_fetch_dimension_address_read /tmp/php-src/Zend/zend_execute.c:2530
    #17 0xaaaace05a94c in zend_fetch_dimension_address_read_R_slow /tmp/php-src/Zend/zend_execute.c:2566
    #18 0xaaaace0ee320 in ZEND_FETCH_DIM_R_SPEC_TMPVAR_CONST_HANDLER /tmp/php-src/Zend/zend_vm_execute.h:15381
    #19 0xaaaace1303e0 in ZEND_FETCH_DIM_FUNC_ARG_SPEC_VAR_CONST_HANDLER /tmp/php-src/Zend/zend_vm_execute.h:22776
    #20 0xaaaace06acec in execute_ex /tmp/php-src/Zend/zend_vm_execute.h:455
    #21 0xaaaacdf8d1fc in zend_call_function /tmp/php-src/Zend/zend_execute_API.c:903
    #22 0xaaaacdf8e1c4 in zend_call_known_function /tmp/php-src/Zend/zend_execute_API.c:992
    #23 0xaaaace216b78 in zend_call_method /tmp/php-src/Zend/zend_interfaces.c:82
    #24 0xaaaace287090 in zend_std_read_dimension /tmp/php-src/Zend/zend_object_handlers.c:927
    #25 0xaaaace05a34c in zend_fetch_dimension_address_read /tmp/php-src/Zend/zend_execute.c:2530
    #26 0xaaaace05a94c in zend_fetch_dimension_address_read_R_slow /tmp/php-src/Zend/zend_execute.c:2566
    #27 0xaaaace0ee320 in ZEND_FETCH_DIM_R_SPEC_TMPVAR_CONST_HANDLER /tmp/php-src/Zend/zend_vm_execute.h:15381
    #28 0xaaaace1303e0 in ZEND_FETCH_DIM_FUNC_ARG_SPEC_VAR_CONST_HANDLER /tmp/php-src/Zend/zend_vm_execute.h:22776
    #29 0xaaaace06acec in execute_ex /tmp/php-src/Zend/zend_vm_execute.h:455
    #30 0xaaaacdf8d1fc in zend_call_function /tmp/php-src/Zend/zend_execute_API.c:903
    #31 0xaaaacdf8e1c4 in zend_call_known_function /tmp/php-src/Zend/zend_execute_API.c:992
    #32 0xaaaace216b78 in zend_call_method /tmp/php-src/Zend/zend_interfaces.c:82
    #33 0xaaaace287090 in zend_std_read_dimension /tmp/php-src/Zend/zend_object_handlers.c:927
    #34 0xaaaace05a34c in zend_fetch_dimension_address_read /tmp/php-src/Zend/zend_execute.c:2530
    #35 0xaaaace05a94c in zend_fetch_dimension_address_read_R_slow /tmp/php-src/Zend/zend_execute.c:2566
    #36 0xaaaace0ee320 in ZEND_FETCH_DIM_R_SPEC_TMPVAR_CONST_HANDLER /tmp/php-src/Zend/zend_vm_execute.h:15381
    #37 0xaaaace1303e0 in ZEND_FETCH_DIM_FUNC_ARG_SPEC_VAR_CONST_HANDLER /tmp/php-src/Zend/zend_vm_execute.h:22776
    #38 0xaaaace06acec in execute_ex /tmp/php-src/Zend/zend_vm_execute.h:455
.... a lot of duplicate one.

Message 3:

Test 'Illuminate\Tests\Integration\Cookie\CookieTest::test_cookie_is_sent_back_with_proper_expire_time_when_should_expire_on_close' started
=================================================================
==20227==ERROR: AddressSanitizer: heap-buffer-overflow on address 0xffffa5d9f808 at pc 0xaaaab6d58450 bp 0xfffff4c293e0 sp 0xfffff4c29400
READ of size 1 at 0xffffa5d9f808 thread T0
    #0 0xaaaab6d5844c in zval_get_type /tmp/php-src/Zend/zend_types.h:553
    #1 0xaaaab6d5ac80 in zend_parse_arg_str /tmp/php-src/Zend/zend_API.h:1995
    #2 0xaaaab6d6d33c in zif_strpos /tmp/php-src/ext/standard/string.c:1929
    #3 0xffff9898dd18  (/dev/zero (deleted)+0x808dd18)

0xffffa5d9f808 is located 8 bytes to the right of 262144-byte region [0xffffa5d5f800,0xffffa5d9f800)
allocated by thread T0 here:
    #0 0xffffae0b1a30 in __interceptor_malloc (/usr/lib/aarch64-linux-gnu/libasan.so.5+0xeda30)
    #1 0xaaaab70cf1b4 in tracked_malloc /tmp/php-src/Zend/zend_alloc.c:2752
    #2 0xaaaab70ce038 in _malloc_custom /tmp/php-src/Zend/zend_alloc.c:2419
    #3 0xaaaab70ce314 in _emalloc /tmp/php-src/Zend/zend_alloc.c:2538
    #4 0xaaaab71f1334 in zend_vm_stack_new_page /tmp/php-src/Zend/zend_execute.h:210
    #5 0xaaaab71f2aa8 in zend_vm_stack_init /tmp/php-src/Zend/zend_execute.c:184
    #6 0xaaaab712f300 in init_executor /tmp/php-src/Zend/zend_execute_API.c:149
    #7 0xaaaab71757e8 in zend_activate /tmp/php-src/Zend/zend.c:1213
    #8 0xaaaab6fde080 in php_request_startup /tmp/php-src/main/main.c:1730
    #9 0xaaaab75c7d84 in do_cli /tmp/php-src/sapi/cli/php_cli.c:931
    #10 0xaaaab75ca4ec in main /tmp/php-src/sapi/cli/php_cli.c:1367
    #11 0xffffac2fc08c in __libc_start_main (/usr/lib/aarch64-linux-gnu/libc.so.6+0x2408c)
    #12 0xaaaab5fda800  (/usr/bin/php+0x622800)

SUMMARY: AddressSanitizer: heap-buffer-overflow /tmp/php-src/Zend/zend_types.h:553 in zval_get_type
Shadow bytes around the buggy address:
  0x200ff4bb3eb0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x200ff4bb3ec0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x200ff4bb3ed0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x200ff4bb3ee0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x200ff4bb3ef0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
=>0x200ff4bb3f00: fa[fa]fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x200ff4bb3f10: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x200ff4bb3f20: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x200ff4bb3f30: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x200ff4bb3f40: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x200ff4bb3f50: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07
  Heap left redzone:       fa
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
  Left alloca redzone:     ca
  Right alloca redzone:    cb
  Shadow gap:              cc
==20227==ABORTING

@shqking
Copy link
Author

shqking commented Oct 21, 2021

Here is the start of the very long backtrace.

#33044 0x0000aaaaac4a2f80 in execute_ex (ex=0xffffaf2b10f0) at /tmp/php-src/Zend/zend_vm_execute.h:54382
#33045 0x0000aaaaac229200 in zend_call_function (fci=0xffffffffafd0, fci_cache=0xffffffffaf90) at /tmp/php-src/Zend/zend_execute_API.c:903
#33046 0x0000aaaaac22a1c8 in zend_call_known_function (fn=0xffff9e68cfc0, object=0xffff75e63020, called_scope=0xffff9e68c360, retval_ptr=0xffffaf2b1040, param_count=1, params=0xffffffffb140, named_params=0x0) at /tmp/php-src/Zend/zend_execute_API.c:992
#33047 0x0000aaaaac4b2bb4 in zend_call_method (object=0xffff75e63020, obj_ce=0xffff9e68c360, fn_proxy=0x0, function_name=0xaaaaad2c00e0 "offsetget", function_name_len=9, retval_ptr=0xffffaf2b1040, param_count=1, arg1=0xffffffffb250, arg2=0x0) at /tmp/php-src/Zend/zend_interfaces.c:82
#33048 0x0000aaaaac5240cc in zend_std_read_dimension (object=0xffff75e63020, offset=0xffff9e5b7830, type=0, rv=0xffffaf2b1040) at /tmp/php-src/Zend/zend_object_handlers.c:927
#33049 0x0000aaaaac2f6350 in zend_fetch_dimension_address_read (result=0xffffaf2b1040, container=0xffffaf2b1050, dim=0xffff9e5b7830, dim_type=8, type=0, is_list=false, slow=1, execute_data=0xffffaf2b0fc0) at /tmp/php-src/Zend/zend_execute.c:2530
#33050 0x0000aaaaac2f6950 in zend_fetch_dimension_address_read_R_slow (container=0xffffaf2b1050, dim=0xffff9e5b7830, opline=0xffff9e5b7ae0, execute_data=0xffffaf2b0fc0) at /tmp/php-src/Zend/zend_execute.c:2566
#33051 0x0000aaaaac389e64 in ZEND_FETCH_DIM_R_SPEC_TMPVAR_CONST_HANDLER (execute_data=0xffffaf2b0fc0) at /tmp/php-src/Zend/zend_vm_execute.h:15301
#33052 0x0000aaaaac3cbf24 in ZEND_FETCH_DIM_FUNC_ARG_SPEC_VAR_CONST_HANDLER (execute_data=0xffffaf2b0fc0) at /tmp/php-src/Zend/zend_vm_execute.h:22696
#33053 0x0000aaaaac4a2f80 in execute_ex (ex=0xffffaf2af820) at /tmp/php-src/Zend/zend_vm_execute.h:54382
#33054 0x0000aaaaac4a3348 in zend_execute (op_array=0xffffaeb13500, return_value=0x0) at /tmp/php-src/Zend/zend_vm_execute.h:58935
#33055 0x0000aaaaac26cf68 in zend_execute_scripts (type=8, retval=0x0, file_count=3) at /tmp/php-src/Zend/zend.c:1744
#33056 0x0000aaaaac0d3400 in php_execute_script (primary_file=0xffffffffdf20) at /tmp/php-src/main/main.c:2534
#33057 0x0000aaaaac6bb240 in do_cli (argc=4, argv=0xffffaed00c90) at /tmp/php-src/sapi/cli/php_cli.c:965
#33058 0x0000aaaaac6bd528 in main (argc=4, argv=0xffffaed00c90) at /tmp/php-src/sapi/cli/php_cli.c:1367

Check the line #33047. Method offsetget is invoked here.
From the first argument of function zend_call_known_function(), fn=0xffff9e68cfc0 and the function type is 2, i.e. USER_FUNCTION.

(gdb) p *(struct _zend_op_array*)0xffff9e68cfc0
$25 = {type = 2 '\002', arg_flags = "\000\000", fn_flags = 33685633, function_name = 0xffff9a61d6d0, scope = 0xffff9e68c360, prototype = 0xffffadf745c0, num_args = 1,
  required_num_args = 1, arg_info = 0xffff9e6886d0, attributes = 0xffff9e6887b8, cache_size = 24, last_var = 1, T = 1, last = 5, opcodes = 0xffff9e688630, run_time_cache__ptr = 0x2e081,
  static_variables_ptr__ptr = 0x0, static_variables = 0x0, vars = 0xffff9e6887f0, refcount = 0x0, last_live_range = 0, last_try_catch = 0, live_range = 0x0, try_catch_array = 0x0,
  filename = 0xffff9e686438, line_start = 154, line_end = 157, doc_comment = 0xffff9e6886f0, last_literal = 2, num_dynamic_func_defs = 0, literals = 0xffff9e688610,
  dynamic_func_defs = 0x0, reserved = {0xffff9e68a440, 0x0, 0x0, 0x0, 0x0, 0x0}}

Hence, the follow-up function zend_call_function() will invoke execute_ex() to call the corresponding handler.

But I suspect

  1. the type should be INTERNAL_FUNCTION instead of USER_FUNCTION. OR
  2. there should be some checks to determine whether it's currently working on recursive calls. HYBRID and CALL+GRV should work well, but CALL+noGRV is not implemented correctly.

@shqking
Copy link
Author

shqking commented Oct 25, 2021

The buggy site should be "/tmp/php-oss/laravel/tests/Integration/Foundation/FoundationServiceProvidersTest.php" at line 21. Let me try to reduce to one small test case.

# current execute data
(gdb) p *(struct _zend_execute_data*) 0xffffad006ed0
$16 = {opline = 0xffff9cee5538, call = 0xffffad006f40, return_value = 0xffffad006eb0, func = 0xffff9ceeb988, This = {value = {lval = 281473203605248, dval = 1.3906624012623154e-309,
      counted = 0xffff96508f00, str = 0xffff96508f00, arr = 0xffff96508f00, obj = 0xffff96508f00, res = 0xffff96508f00, ref = 0xffff96508f00, ast = 0xffff96508f00, zv = 0xffff96508f00,
      ptr = 0xffff96508f00, ce = 0xffff96508f00, func = 0xffff96508f00, ww = {w1 = 2521861888, w2 = 65535}}, u1 = {type_info = 776, v = {type = 8 '\b', type_flags = 3 '\003', u = {
          extra = 0}}}, u2 = {next = 0, cache_slot = 0, opline_num = 0, lineno = 0, num_args = 0, fe_pos = 0, fe_iter_idx = 0, property_guard = 0, constant_flags = 0, extra = 0}},
  prev_execute_data = 0xffffad006e30, symbol_table = 0x0, run_time_cache = 0xffff849ff730, extra_named_params = 0xffff9c4f04b0}
(gdb) p *(struct _zend_op_array*)0xffff9ceeb988
$17 = {type = 2 '\002', arg_flags = "\000\000", fn_flags = 33685633, function_name = 0xffff9a545310, scope = 0xffff9cee6ca8, prototype = 0x0, num_args = 0, required_num_args = 0,
  arg_info = 0x0, attributes = 0x0, cache_size = 48, last_var = 0, T = 2, last = 13, opcodes = 0xffff9cee54d8, run_time_cache__ptr = 0x1e591, static_variables_ptr__ptr = 0x0,
  static_variables = 0x0, vars = 0x0, refcount = 0x0, last_live_range = 0, last_try_catch = 0, live_range = 0x0, try_catch_array = 0x0, filename = 0xffff9cee52f0, line_start = 19,
  line_end = 23, doc_comment = 0xffff9cee5678, last_literal = 6, num_dynamic_func_defs = 0, literals = 0xffff9cee5478, dynamic_func_defs = 0x0, reserved = {0xffff9cee6478, 0x0, 0x0,
    0x0, 0x0, 0x0}}
(gdb) p *(const zend_op*)0xffff9cee5538
$18 = {handler = 0xaaaaac3cc338 <ZEND_FETCH_DIM_FUNC_ARG_SPEC_VAR_CONST_HANDLER>, op1 = {constant = 96, var = 96, num = 96, opline_num = 96, jmp_offset = 96}, op2 = {
    constant = 4294967152, var = 4294967152, num = 4294967152, opline_num = 4294967152, jmp_offset = 4294967152}, result = {constant = 80, var = 80, num = 80, opline_num = 80,
    jmp_offset = 80}, extended_value = 0, lineno = 21, opcode = 93 ']', op1_type = 4 '\004', op2_type = 1 '\001', result_type = 4 '\004'}
(gdb) p (char *)0xffff9a545328
$19 = 0xffff9a545328 "it_can_boot_service_provider_registered_from_another_service_provider"
(gdb) p (char *) 0xffff9cee5308
$20 = 0xffff9cee5308 "/tmp/php-oss/laravel/tests/Integration/Foundation/FoundationServiceProvidersTest.php"

# prev
(gdb) p *(struct _zend_execute_data*) 0xffffad006e30
$21 = {opline = 0xffff9ac76698, call = 0x0, return_value = 0xffffad006e10, func = 0xffff9ad07900, This = {value = {lval = 281473203605248, dval = 1.3906624012623154e-309,
      counted = 0xffff96508f00, str = 0xffff96508f00, arr = 0xffff96508f00, obj = 0xffff96508f00, res = 0xffff96508f00, ref = 0xffff96508f00, ast = 0xffff96508f00, zv = 0xffff96508f00,
      ptr = 0xffff96508f00, ce = 0xffff96508f00, func = 0xffff96508f00, ww = {w1 = 2521861888, w2 = 65535}}, u1 = {type_info = 776, v = {type = 8 '\b', type_flags = 3 '\003', u = {
          extra = 0}}}, u2 = {next = 0, cache_slot = 0, opline_num = 0, lineno = 0, num_args = 0, fe_pos = 0, fe_iter_idx = 0, property_guard = 0, constant_flags = 0, extra = 0}},
  prev_execute_data = 0xffffad006d60, symbol_table = 0x100000307, run_time_cache = 0xffff930dee80, extra_named_params = 0x200000307}
(gdb) p *(struct _zend_op_array*)0xffff9ad07900
$22 = {type = 2 '\002', arg_flags = "\000\000", fn_flags = 2181169282, function_name = 0xffff9a3d8d60, scope = 0xffff9acfe3b0, prototype = 0x0, num_args = 0, required_num_args = 0,
  arg_info = 0x0, attributes = 0x0, cache_size = 352, last_var = 3, T = 2, last = 156, opcodes = 0xffff9ac76338, run_time_cache__ptr = 0x3f31, static_variables_ptr__ptr = 0x0,
  static_variables = 0x0, vars = 0xffff9ac77880, refcount = 0x0, last_live_range = 11, last_try_catch = 1, live_range = 0xffff9ac776b8, try_catch_array = 0xffff9ac77870,
  filename = 0xffff9ac61618, line_start = 1514, line_end = 1619, doc_comment = 0xffff9ac77740, last_literal = 44, num_dynamic_func_defs = 0, literals = 0xffff9ac76078,
  dynamic_func_defs = 0x0, reserved = {0xffff9ac97fd8, 0x0, 0x0, 0x0, 0x0, 0x0}}
(gdb) p *(const zend_op*)0xffff9ac76698
$23 = {handler = 0xaaaaac314a94 <ZEND_DO_FCALL_SPEC_RETVAL_USED_HANDLER>, op1 = {constant = 4294967295, var = 4294967295, num = 4294967295, opline_num = 4294967295,
    jmp_offset = 4294967295}, op2 = {constant = 4294967295, var = 4294967295, num = 4294967295, opline_num = 4294967295, jmp_offset = 4294967295}, result = {constant = 128, var = 128,
    num = 128, opline_num = 128, jmp_offset = 128}, extended_value = 1, lineno = 1527, opcode = 60 '<', op1_type = 0 '\000', op2_type = 0 '\000', result_type = 4 '\004'}
(gdb)  p (char *) 0xffff9a3d8d78
$24 = 0xffff9a3d8d78 "runTest"
(gdb) p (char *)0xffff9ac61630
$25 = 0xffff9ac61630 "/tmp/php-oss/laravel/vendor/phpunit/phpunit/src/Framework/TestCase.php"

@dstogov
Copy link

dstogov commented Oct 25, 2021

I hope this should be fixed by php/php-src@3190062

@shqking
Copy link
Author

shqking commented Oct 26, 2021

I hope this should be fixed by php/php-src@3190062

Thanks a lot for your fix.
Just tested that, running laravel with all configurations (i.e. NTS/ZTS, HYBRID/CALL+GRV/CALL+noGRV) can pass now with this patch.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment