swoole-src icon indicating copy to clipboard operation
swoole-src copied to clipboard

Published 20 hours ago • verified publisher icon swoole

Swoole will be crashed with some hook flags.

Open chris-lee-lb opened this issue 2 years ago • 5 comments

Please answer these questions before submitting your issue. Thanks!

  1. What did you do? If possible, provide a simple script for reproducing the error.

I use swoole with this laravel extension - laravel/octane (https://laravel.com/docs/8.x/octane)

We've adjust all the swoole configs in config/octane.php

'swoole'             => [
        'options' => [
            'enable_coroutine'   => true,
            'hook_flags'         => SWOOLE_HOOK_FILE | SWOOLE_HOOK_STDIO,
            'log_level'          => SWOOLE_LOG_TRACE,
            'trace_flags'        => SWOOLE_TRACE_ALL,
            'open_tcp_keepalive' => true,
            'tcp_keepidle'       => 620,
            'tcp_keepinterval'   => 1,
            'tcp_keepcount'      => 5,
        ],
    ],

github repository which contains reproducing scripts : https://github.com/chris-lee-lb/swoole-debug-2021-12-21 docker image which contains reproducing scripts : https://hub.docker.com/r/protosschris/swoole-debug-2021-12-21

and then you run docker instance with :

docker run -d -e "PHP_OPCACHE_ENABLED=true" --name test -p 80:80 protosschris/swoole-debug-2021-12-21:debug

and for test curl routes :

curl -vvv 'http://localhost'

  1. What did you expect to see?

Successfully running.

  1. What did you see instead?

Crashed.

  1. What version of Swoole are you using (show your php --ri swoole)?
bash-5.1# php --ri swoole

swoole

Swoole => enabled
Author => Swoole Team <[email protected]>
Version => 4.8.3
Built => Dec 21 2021 07:02:30
coroutine => enabled with boost asm context
debug => enabled
trace_log => enabled
epoll => enabled
eventfd => enabled
signalfd => enabled
spinlock => enabled
rwlock => enabled
openssl => OpenSSL 1.1.1l  24 Aug 2021
dtls => enabled
http2 => enabled
json => enabled
curl-native => enabled
pcre => enabled
zlib => 1.2.11
brotli => E16777225/D16777225
mutex_timedlock => enabled
pthread_barrier => enabled
mysqlnd => enabled
async_redis => enabled

Directive => Local Value => Master Value
swoole.enable_coroutine => On => On
swoole.enable_library => On => On
swoole.enable_preemptive_scheduler => Off => Off
swoole.display_errors => On => On
swoole.use_shortname => On => On
swoole.unixsock_buffer_size => 8388608 => 8388608
  1. What is your machine environment used (show your uname -a & php -v & gcc -v) ?
bash-5.1# uname -a
Linux passport-debug-5547fbb948-phrh9 5.4.120+ #1 SMP Wed Aug 18 10:20:32 PDT 2021 x86_64 Linux

bash-5.1# php -v
PHP 8.0.13 (cli) (built: Nov 30 2021 07:57:55) ( NTS )
Copyright (c) The PHP Group
Zend Engine v4.0.13, Copyright (c) Zend Technologies
    with Zend OPcache v8.0.13, Copyright (c), by Zend Technologies

bash-5.1# cat /etc/os-release
NAME="Alpine Linux"
ID=alpine
VERSION_ID=3.15.0
PRETTY_NAME="Alpine Linux v3.15"
HOME_URL="https://alpinelinux.org/"
BUG_REPORT_URL="https://bugs.alpinelinux.org/"

GCC version : 10.3.1_git20211027-r0

PS : I can successfully running for docker for mac with my Mac Pro, but crashed with GCP GKE 1.20.10-gke.1600

chris-lee-lb avatar Dec 21 '21 12:12 chris-lee-lb

And here are some debug & trace logs

====== flag : SWOOLE_HOOK_FILE ======

[2021-12-21 11:32:26 @718.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=160, size=152
[2021-12-21 11:32:26 @718.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:32:26 @718.0]	TRACE	Table::get_memory_size(:113): _memory_size=35248, _row_num=307, _row_memory_size=104
[2021-12-21 11:32:26 @718.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:32:26 @718.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=160, size=152
[2021-12-21 11:32:26 @718.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:32:26 @718.0]	TRACE	Table::get_memory_size(:113): _memory_size=12415936, _row_num=1228, _row_memory_size=10100
[2021-12-21 11:32:26 @718.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:32:26 @718.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=160, size=152
[2021-12-21 11:32:26 @718.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:32:26 @718.0]	TRACE	Table::get_memory_size(:113): _memory_size=1363936, _row_num=1228, _row_memory_size=1100
[2021-12-21 11:32:26 @718.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:32:26 @718.0]	TRACE	ServerObject::on_before_start(:1017): Create Server: host=0.0.0.0, port=80, mode=2, type=1
[2021-12-21 11:32:26 @718.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:32:26 @718.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:32:26 @718.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=280, size=272
[2021-12-21 11:32:26 @718.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:32:26 @718.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:32:26 @718.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:32:26 @718.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:32:26 @718.0]	TRACE	ReactorEpoll::add(:107): add events[fd=23#0, type=9, events=512]
[2021-12-21 11:32:26 @718.0]	TRACE	ReactorEpoll::add(:107): add events[fd=8#0, type=1, events=512]
[2021-12-21 11:32:26 #718.2]	TRACE	Timer::add(:144): id=1, exec_msec=1000, msec=1000, round=0, exist=1
[2021-12-21 11:32:26 #718.1]	TRACE	ReactorEpoll::add(:107): add events[fd=17#1, type=3, events=512]
[2021-12-21 11:32:26 #718.0]	TRACE	ReactorEpoll::add(:107): add events[fd=15#0, type=3, events=512]
[2021-12-21 11:32:26 #718.2]	TRACE	Context::Context(:53): alloc stack: size=2097152, ptr=0x7fb08d146150
[2021-12-21 11:32:26 #718.2]	TRACE	PHPCoroutine::main_func(:766): Create coro id: 1, origin cid: -1, coro total count: 1, heap size: 2298504
[2021-12-21 11:32:26 #718.2]	TRACE	ReactorEpoll::add(:107): add events[fd=26#2, type=5, events=512]
[2021-12-21 11:32:26 #718.2]	DEBUG	ThreadPool::dispatch(:155): push and notify one: 1640086346.199556
[2021-12-21 11:32:26 #718.2]	TRACE	PHPCoroutine::on_yield(:609): from cid=1 to cid=-1
[2021-12-21 11:32:26 @725.0]	TRACE	ReactorEpoll::add(:107): add events[fd=16#0, type=3, events=512]
[2021-12-21 11:32:26 *725.1]	TRACE	ReactorEpoll::add(:107): add events[fd=24#0, type=9, events=512]
[2021-12-21 11:32:26 @724.0]	TRACE	ReactorEpoll::add(:107): add events[fd=14#0, type=3, events=512]
[2021-12-21 11:32:26 *725.1]	TRACE	Context::Context(:53): alloc stack: size=2097152, ptr=0x7fb08cbff0c0
[2021-12-21 11:32:26 *725.1]	TRACE	PHPCoroutine::main_func(:766): Create coro id: 1, origin cid: -1, coro total count: 1, heap size: 2298504
[2021-12-21 11:32:26 *724.0]	TRACE	ReactorEpoll::add(:107): add events[fd=24#0, type=9, events=512]
[2021-12-21 11:32:26 *724.0]	TRACE	Context::Context(:53): alloc stack: size=2097152, ptr=0x7fb08cbff0c0
[2021-12-21 11:32:26 *724.0]	TRACE	PHPCoroutine::main_func(:766): Create coro id: 1, origin cid: -1, coro total count: 1, heap size: 2298504
[2021-12-21 11:32:26 #718.0]	DEBUG	ThreadPool::create_thread(:241): pop 1 event: 1640086346.215266
[2021-12-21 11:32:26 #718.0]	TRACE	ThreadPool::create_thread(:254): aio_thread failed. ret=0, error=22
[2021-12-21 11:32:26 #718.0]	DEBUG	ThreadPool::create_thread(:241): no event: 1640086346.215356
[2021-12-21 11:32:26 #718.0]	DEBUG	ThreadPool::create_thread(:241): no event: 1640086346.215607
[2021-12-21 11:32:26 $719.0]	TRACE	Server::kill_event_workers(:632): [Manager]kill worker processor
[2021-12-21 11:32:26 $719.0]	TRACE	Server::kill_event_workers(:632): [Manager]kill worker processor
[2021-12-21 11:32:26 *725.1]	TRACE	PHPCoroutine::on_close(:667): coro close cid=1 and resume to -1, 0 remained. usage size: 3768088. malloc size: 2097152
[2021-12-21 11:32:26 *725.1]	TRACE	Context::~Context(:90): free stack: ptr=0x7fb08cbff0c0
[2021-12-21 11:32:26 *725.1]	TRACE	ReactorEpoll::del(:128): remove event[reactor_id=0|fd=16]
[2021-12-21 11:32:26 *725.1]	TRACE	ReactorEpoll::del(:128): remove event[reactor_id=0|fd=24]
[2021-12-21 11:32:26 *724.0]	TRACE	PHPCoroutine::on_close(:667): coro close cid=1 and resume to -1, 0 remained. usage size: 3767128. malloc size: 2097152
[2021-12-21 11:32:26 *724.0]	TRACE	Context::~Context(:90): free stack: ptr=0x7fb08cbff0c0
[2021-12-21 11:32:26 *724.0]	TRACE	ReactorEpoll::del(:128): remove event[reactor_id=0|fd=14]
[2021-12-21 11:32:26 *724.0]	TRACE	ReactorEpoll::del(:128): remove event[reactor_id=0|fd=24]

====== flag : SWOOLE_HOOK_STDIO ======

[2021-12-21 11:50:32 @945.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=160, size=152
[2021-12-21 11:50:32 @945.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:50:32 @945.0]	TRACE	Table::get_memory_size(:113): _memory_size=35248, _row_num=307, _row_memory_size=104
[2021-12-21 11:50:32 @945.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:50:32 @945.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=160, size=152
[2021-12-21 11:50:32 @945.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:50:32 @945.0]	TRACE	Table::get_memory_size(:113): _memory_size=12415936, _row_num=1228, _row_memory_size=10100
[2021-12-21 11:50:32 @945.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:50:32 @945.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=160, size=152
[2021-12-21 11:50:32 @945.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:50:32 @945.0]	TRACE	Table::get_memory_size(:113): _memory_size=1363936, _row_num=1228, _row_memory_size=1100
[2021-12-21 11:50:32 @945.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:50:32 @945.0]	TRACE	ServerObject::on_before_start(:1017): Create Server: host=0.0.0.0, port=80, mode=2, type=1
[2021-12-21 11:50:32 @945.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:50:32 @945.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:50:32 @945.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=280, size=272
[2021-12-21 11:50:32 @945.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:50:32 @945.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:50:32 @945.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:50:32 @945.0]	TRACE	GlobalMemory::alloc(:96): alloc_size=56, size=48
[2021-12-21 11:50:32 @945.0]	TRACE	ReactorEpoll::add(:107): add events[fd=23#0, type=9, events=512]
[2021-12-21 11:50:32 @945.0]	TRACE	ReactorEpoll::add(:107): add events[fd=8#0, type=1, events=512]
[2021-12-21 11:50:32 #945.2]	TRACE	Timer::add(:144): id=1, exec_msec=1000, msec=1000, round=0, exist=1
[2021-12-21 11:50:32 #945.0]	TRACE	ReactorEpoll::add(:107): add events[fd=15#0, type=3, events=512]
[2021-12-21 11:50:32 #945.1]	TRACE	ReactorEpoll::add(:107): add events[fd=17#1, type=3, events=512]
[2021-12-21 11:50:32 #945.2]	TRACE	Context::Context(:53): alloc stack: size=2097152, ptr=0x7f28f55ff150
[2021-12-21 11:50:32 #945.2]	TRACE	PHPCoroutine::main_func(:766): Create coro id: 1, origin cid: -1, coro total count: 1, heap size: 2298504
[2021-12-21 11:50:32 #945.2]	TRACE	ReactorEpoll::add(:107): add events[fd=27#2, type=5, events=512]
[2021-12-21 11:50:32 #945.2]	DEBUG	ThreadPool::dispatch(:155): push and notify one: 1640087432.947014
[2021-12-21 11:50:32 #945.2]	TRACE	PHPCoroutine::on_yield(:609): from cid=1 to cid=-1
[2021-12-21 11:50:32 @951.0]	TRACE	ReactorEpoll::add(:107): add events[fd=14#0, type=3, events=512]
[2021-12-21 11:50:32 *951.0]	TRACE	ReactorEpoll::add(:107): add events[fd=24#0, type=9, events=512]
[2021-12-21 11:50:32 *951.0]	TRACE	Context::Context(:53): alloc stack: size=2097152, ptr=0x7f28f10350c0
[2021-12-21 11:50:32 *951.0]	TRACE	PHPCoroutine::main_func(:766): Create coro id: 1, origin cid: -1, coro total count: 1, heap size: 2298504
[2021-12-21 11:50:32 *951.0]	TRACE	ReactorEpoll::add(:107): add events[fd=26#0, type=5, events=512]
[2021-12-21 11:50:32 *951.0]	DEBUG	ThreadPool::dispatch(:155): push and notify one: 1640087432.951944
[2021-12-21 11:50:32 *951.0]	TRACE	PHPCoroutine::on_yield(:609): from cid=1 to cid=-1
[2021-12-21 11:50:32 @952.0]	TRACE	ReactorEpoll::add(:107): add events[fd=16#0, type=3, events=512]
[2021-12-21 11:50:32 *952.1]	TRACE	ReactorEpoll::add(:107): add events[fd=24#0, type=9, events=512]
[2021-12-21 11:50:32 *952.1]	TRACE	Context::Context(:53): alloc stack: size=2097152, ptr=0x7f28f10350c0
[2021-12-21 11:50:32 *952.1]	TRACE	PHPCoroutine::main_func(:766): Create coro id: 1, origin cid: -1, coro total count: 1, heap size: 2298504
[2021-12-21 11:50:32 *952.1]	TRACE	ReactorEpoll::add(:107): add events[fd=26#0, type=5, events=512]
[2021-12-21 11:50:32 *952.1]	DEBUG	ThreadPool::dispatch(:155): push and notify one: 1640087432.972077
[2021-12-21 11:50:32 *952.1]	TRACE	PHPCoroutine::on_yield(:609): from cid=1 to cid=-1
[2021-12-21 11:50:32 $946.0]	TRACE	Server::kill_event_workers(:632): [Manager]kill worker processor
[2021-12-21 11:50:32 $946.0]	TRACE	Server::kill_event_workers(:632): [Manager]kill worker processor
[2021-12-21 11:50:32 *951.0]	DEBUG	ThreadPool::create_thread(:241): pop 1 event: 1640087432.976708
[2021-12-21 11:50:32 *951.0]	TRACE	ThreadPool::create_thread(:254): aio_thread failed. ret=0, error=22
[2021-12-21 11:50:32 *951.0]	DEBUG	ThreadPool::create_thread(:241): no event: 1640087432.976968
[2021-12-21 11:50:32 *951.0]	DEBUG	ThreadPool::create_thread(:241): no event: 1640087432.987384
[2021-12-21 11:50:32 *952.1]	DEBUG	ThreadPool::create_thread(:241): pop 1 event: 1640087432.988448
[2021-12-21 11:50:32 *952.1]	TRACE	ThreadPool::create_thread(:254): aio_thread failed. ret=0, error=22
[2021-12-21 11:50:32 *952.1]	DEBUG	ThreadPool::create_thread(:241): no event: 1640087432.988541
[2021-12-21 11:50:32 *952.1]	DEBUG	ThreadPool::create_thread(:241): no event: 1640087432.988582

chris-lee-lb avatar Dec 21 '21 12:12 chris-lee-lb

And another information that may be helpful, It was successfully running if I turn off OPCache extension.

I use OPCache with preload feature. My preload file is located in root dir preload.php

chris-lee-lb avatar Dec 21 '21 12:12 chris-lee-lb

Why do you need preload with Swoole?

Your code only loads once on server start.

ValiDrv avatar Dec 22 '21 12:12 ValiDrv

@ValiDrv it's less about why, but more about how it works with PHP 8.0 and not on PHP 8.1.

sikhlana avatar Jan 24 '22 01:01 sikhlana

I can confirm that just having opcache extension installed causes worker crashes for me too. I guess opcache probably isn't necessary, but I had it enabled out of habit from other projects. It should probably be noted somewhere in the documentation that these two extensions aren't compatible.

RedChops avatar Mar 11 '22 19:03 RedChops