Ratchet on 100% CPU load

Hi.
During the last month, I am having a problem with running a Ratchet server in a production environment, suddenly the process goes from normally using 0-1% of a CPU core to 98-100%, the websocket server still working but it takes longer to respond, this happens in a variety of ways, sometimes it takes a few hours to happen and others it takes days / weeks.
When it enters this state it does not exit again until I kill the process and supervisor starts a new one.
I am also checking the logic of my application so that it is not a problem on my part.
Apache version
Server Version: Apache/2.4.51 (cPanel) OpenSSL/1.1.1g mod_bwlimited/1.4
Server MPM: event
Server Built: Nov 7 2021 17:32:31

PHP version
PHP 8.0.12 (cli) (built: Nov 10 2021 01:18:26) ( NTS )
Copyright (c) The PHP Group
Zend Engine v4.0.12, Copyright (c) Zend Technologies
    with Zend OPcache v8.0.12, Copyright (c), by Zend Technologies

Ratchet version being used
cboden/ratchet v0.4.4 PHP WebSocket library
├──guzzlehttp/psr7 v1.8.3
├──ratchet/rfc6455 v0.3.1
├──react/event-loop v1.2.0
├──react/socket v1.10.0
├──symfony/http-foundation v6.0.1
└──symfony/routing v4.4.34

Event loop
ExtEvLoop
ev (1.1.4)

supervisor.conf
[unix_http_server]
file = /tmp/supervisor.sock

[supervisord]
logfile          = ./logs/supervisord.log
logfile_maxbytes = 50MB
logfile_backups  = 10
loglevel         = info
pidfile          = /tmp/supervisord.pid
nodaemon         = false
minfds           = 4096
minprocs         = 200

[rpcinterface:supervisor]
supervisor.rpcinterface_factory = supervisor.rpcinterface:make_main_rpcinterface

[supervisorctl]
serverurl = unix:///tmp/supervisor.sock

[program:ratchet]
directory				= /home/username/public_html
command                 = bash -c "ulimit -n 10000; exec php chat.php"
process_name            = Chat
numprocs                = 1
autostart               = true
autorestart             = true
user                    = root
stdout_logfile          = ./logs/chat_info.log
stdout_logfile_maxbytes = 1MB
stderr_logfile          = ./logs/chat_error.log
stderr_logfile_maxbytes = 1MB

I have this code in the app, but there is no record in chat_info.log or chat_error.log
public function onError(ConnectionInterface $conn, \Exception $e)
{
	echo "An error has occurred: {$e->getMessage()}\n";

	$conn->close();
}

This is what appears if I run strace in the pid
strace

--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10400) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10400) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10400) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10400) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10400) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10399) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10399) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10399) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10399) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10399) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10398) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10398) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10398) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10398) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10398) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10397) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10397) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10397) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10397) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)

Thank you for your replies.

What happens at the of the sudden increase in CPU usage, like more users/messages/anything?
Are you using any blocking code such as PDO or sleep or file_get_contents?

I still haven't been able to see how many users there are when it happens, since I realize hours later, but there are currently 200 users and there must be probably about 300/400 at their peak. currently the onMessage function receives about 10 messages per minute.

Are you using any blocking code such as PDO or sleep or file_get_contents?

My code has SQL queries and also uses the filemtime function.
I don't know if this has something to do with it, but I just noticed that the code that I use in onOpen and onColse to save the client is different from the one in the documentation.
I have something like to this:
public function onOpen(ConnectionInterface $conn)
{
	$this->clients[$conn->resourceId] = $conn;
}

public function onClose(ConnectionInterface $conn)
{
	// The connection is closed, remove it, as we can no longer send it messages
	unset($this->clients[$conn->resourceId]);
}

Thank for your replie.

You can make use of xdebug to find out exaclty where your app is struggling.

@ollm two items come to mind: 1) You are running PHP8.0 Is this a good idea for production server? I read in some of the issues that ZMQ has trouble with PHP7.2+. I had trouble with PHP7.2+ on windows, but so far not on Ubuntu. Also not on a production server yet.  Also in one of issues from years ago, it was mentioned that we need to force garbage collection once in a while.
Just some observation, hope it helps.

The other thing to try is use either artilery or autobahn to stress test your application or server, and see if this happens again.

I have been testing wsstat and artillery to stress the server and from 1000-1200 some of the new connections start to fail (wsstat shows error 429 and artillery shows ECONNRESET), up to 2200 connections, I don't know if this could be due to the websocket going through Cloudflare or it is some problem with my internet connection, I had seen in other issues that they have problems when exceeding 1024 connections, but it seems that this is not the same problem, during the stress test the process reaches 100% CPU, but once finished it returns to normal values.
Now I am testing with PHP 7.2, which is the oldest version that I currently have installed on the server.
Thanks for all replies.

Hi.
With PHP 7.2 I still have the same problem, I have been testing xdebug to see where it happens and the Broken pipe error appears between lines 129 and 139 of https://github.com/reactphp/stream/blob/70d6e15d5f90730651558852c74fbb767fd9215b/src/WritableResourceStream.php although it seems to be more related to the fwrite of line 124: https://github.com/reactphp/stream/blob/70d6e15d5f90730651558852c74fbb767fd9215b/src/WritableResourceStream.php#L124
strace

strace: Process 1707488 attached
recvfrom(133, "step_into -i 2797\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 306) = 306
write(133, "322\0<?xml version=\"1.0\" encoding"..., 327) = 327
recvfrom(133, "step_into -i 2798\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 343) = 343
write(133, "359\0<?xml version=\"1.0\" encoding"..., 364) = 364
recvfrom(133, "step_into -i 2799\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 344) = 344
write(133, "360\0<?xml version=\"1.0\" encoding"..., 365) = 365
recvfrom(133, "step_into -i 2800\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 342) = 342
write(133, "358\0<?xml version=\"1.0\" encoding"..., 363) = 363
recvfrom(133, "step_into -i 2801\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 342) = 342
write(133, "358\0<?xml version=\"1.0\" encoding"..., 363) = 363
recvfrom(133, "step_into -i 2802\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 342) = 342
write(133, "358\0<?xml version=\"1.0\" encoding"..., 363) = 363
recvfrom(133, "step_into -i 2803\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 353) = 353
write(133, "369\0<?xml version=\"1.0\" encoding"..., 374) = 374
recvfrom(133, "step_into -i 2804\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 342) = 342
write(133, "358\0<?xml version=\"1.0\" encoding"..., 363) = 363
recvfrom(133, "step_into -i 2805\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 342) = 342
write(133, "358\0<?xml version=\"1.0\" encoding"..., 363) = 363
recvfrom(133, "step_into -i 2806\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 342) = 342
write(133, "358\0<?xml version=\"1.0\" encoding"..., 363) = 363
recvfrom(133, "step_into -i 2807\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 342) = 342
write(133, "358\0<?xml version=\"1.0\" encoding"..., 363) = 363
recvfrom(133, "step_into -i 2808\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 344) = 344
write(133, "360\0<?xml version=\"1.0\" encoding"..., 365) = 365
recvfrom(133, "step_into -i 2809\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 340) = 340
write(133, "356\0<?xml version=\"1.0\" encoding"..., 361) = 361
recvfrom(133, "step_into -i 2810\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 341) = 341
write(133, "357\0<?xml version=\"1.0\" encoding"..., 362) = 362
recvfrom(133, "step_into -i 2811\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 340) = 340
write(133, "356\0<?xml version=\"1.0\" encoding"..., 361) = 361
recvfrom(133, "step_into -i 2812\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 350) = 350
write(133, "366\0<?xml version=\"1.0\" encoding"..., 371) = 371
recvfrom(133, "step_into -i 2813\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 350) = 350
write(133, "366\0<?xml version=\"1.0\" encoding"..., 371) = 371
recvfrom(133, "step_into -i 2814\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 319) = 319
write(133, "335\0<?xml version=\"1.0\" encoding"..., 340) = 340
recvfrom(133, "step_into -i 2815\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 350) = 350
write(133, "366\0<?xml version=\"1.0\" encoding"..., 371) = 371
recvfrom(133, "step_into -i 2816\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 350) = 350
write(133, "366\0<?xml version=\"1.0\" encoding"..., 371) = 371
recvfrom(133, "step_into -i 2817\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 336) = 336
write(133, "352\0<?xml version=\"1.0\" encoding"..., 357) = 357
recvfrom(133, "step_into -i 2818\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 328) = 328
write(133, "344\0<?xml version=\"1.0\" encoding"..., 349) = 349
recvfrom(133, "step_into -i 2819\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 328) = 328
write(133, "344\0<?xml version=\"1.0\" encoding"..., 349) = 349
recvfrom(133, "step_into -i 2820\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 338) = 338
write(133, "354\0<?xml version=\"1.0\" encoding"..., 359) = 359
recvfrom(133, "step_into -i 2821\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 338) = 338
write(133, "354\0<?xml version=\"1.0\" encoding"..., 359) = 359
recvfrom(133, "step_into -i 2822\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 338) = 338
write(133, "354\0<?xml version=\"1.0\" encoding"..., 359) = 359
recvfrom(133, "step_into -i 2823\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 338) = 338
write(133, "354\0<?xml version=\"1.0\" encoding"..., 359) = 359
recvfrom(133, "step_into -i 2824\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
write(21, "\27\3\3\0\25\2553\354\364)\367\271\244\0312|\261B\377\252\25&\233v\302\330", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=1707488, si_uid=0} ---
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 338) = 338
write(133, "354\0<?xml version=\"1.0\" encoding"..., 359) = 359
recvfrom(133, "step_into -i 2825\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 338) = 338
write(133, "354\0<?xml version=\"1.0\" encoding"..., 359) = 359
recvfrom(133, "step_into -i 2826\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 338) = 338
write(133, "354\0<?xml version=\"1.0\" encoding"..., 359) = 359
recvfrom(133, "step_into -i 2827\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 338) = 338
write(133, "354\0<?xml version=\"1.0\" encoding"..., 359) = 359
recvfrom(133, "step_into -i 2828\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 338) = 338
write(133, "354\0<?xml version=\"1.0\" encoding"..., 359) = 359
recvfrom(133, "step_into -i 2829\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 338) = 338
write(133, "354\0<?xml version=\"1.0\" encoding"..., 359) = 359
recvfrom(133, "step_into -i 2830\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 338) = 338
write(133, "354\0<?xml version=\"1.0\" encoding"..., 359) = 359
recvfrom(133, "step_into -i 2831\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 328) = 328
write(133, "344\0<?xml version=\"1.0\" encoding"..., 349) = 349
recvfrom(133, "step_into -i 2832\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 329) = 329
write(133, "345\0<?xml version=\"1.0\" encoding"..., 350) = 350
recvfrom(133, "step_into -i 2833\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 339) = 339
write(133, "355\0<?xml version=\"1.0\" encoding"..., 360) = 360
recvfrom(133, "step_into -i 2834\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 339) = 339
write(133, "355\0<?xml version=\"1.0\" encoding"..., 360) = 360
recvfrom(133, "step_into -i 2835\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 339) = 339
write(133, "355\0<?xml version=\"1.0\" encoding"..., 360) = 360
recvfrom(133, "step_into -i 2836\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 329) = 329
write(133, "345\0<?xml version=\"1.0\" encoding"..., 350) = 350
recvfrom(133, "step_into -i 2837\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 339) = 339
write(133, "355\0<?xml version=\"1.0\" encoding"..., 360) = 360
recvfrom(133, "step_into -i 2838\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 329) = 329
write(133, "345\0<?xml version=\"1.0\" encoding"..., 350) = 350
recvfrom(133, "step_into -i 2839\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 329) = 329
write(133, "345\0<?xml version=\"1.0\" encoding"..., 350) = 350
recvfrom(133, "step_into -i 2840\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 329) = 329
write(133, "345\0<?xml version=\"1.0\" encoding"..., 350) = 350
recvfrom(133, "step_into -i 2841\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 329) = 329
write(133, "345\0<?xml version=\"1.0\" encoding"..., 350) = 350
recvfrom(133, "step_into -i 2842\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 329) = 329
write(133, "345\0<?xml version=\"1.0\" encoding"..., 350) = 350
recvfrom(133, "step_into -i 2843\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
epoll_wait(7, [{EPOLLOUT|EPOLLHUP, {u32=21, u64=11300058955797}}, {EPOLLIN, {u32=167, u64=8177617731751}}, {EPOLLIN, {u32=17, u64=19116899434513}}, {EPOLLIN, {u32=102, u64=13713830576230}}, {EPOLLIN, {u32=8, u64=4294967304}}, {EPOLLIN, {u32=81, u64=12468290060369}}, {EPOLLIN, {u32=30, u64=20143396618270}}, {EPOLLIN, {u32=66, u64=16642998272066}}, {EPOLLIN, {u32=98, u64=15401752723554}}, {EPOLLIN, {u32=170, u64=7816840478890}}], 262, 1) = 10
epoll_ctl(7, EPOLL_CTL_MOD, 21, {EPOLLOUT, {u32=21, u64=11300058955797}}) = 0
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 329) = 329
write(133, "345\0<?xml version=\"1.0\" encoding"..., 350) = 350
recvfrom(133, "step_into -i 2844\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 330) = 330
write(133, "346\0<?xml version=\"1.0\" encoding"..., 351) = 351
recvfrom(133, "step_into -i 2845\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 344) = 344
write(133, "360\0<?xml version=\"1.0\" encoding"..., 365) = 365
recvfrom(133, "step_into -i 2846\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 344) = 344
write(133, "360\0<?xml version=\"1.0\" encoding"..., 365) = 365
recvfrom(133, "step_into -i 2847\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 347) = 347
write(133, "363\0<?xml version=\"1.0\" encoding"..., 368) = 368
recvfrom(133, "step_into -i 2848\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 352) = 352
write(133, "368\0<?xml version=\"1.0\" encoding"..., 373) = 373
recvfrom(133, "step_into -i 2849\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 347) = 347
write(133, "363\0<?xml version=\"1.0\" encoding"..., 368) = 368
recvfrom(133, "step_into -i 2850\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 344) = 344
write(133, "360\0<?xml version=\"1.0\" encoding"..., 365) = 365
recvfrom(133, "step_into -i 2851\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488

xdebug

(cmd) step_into
2797 | step_into > break/ok
2797 | file:///home/username/public_html/includes/chat.php:3636

(cmd)
2798 | step_into > break/ok
2798 | file:///home/username/public_html/vendor/cboden/ratchet/src/Ratchet/WebSocket/WsServer.php:76

(cmd)
2799 | step_into > break/ok
2799 | file:///home/username/public_html/vendor/cboden/ratchet/src/Ratchet/WebSocket/WsServer.php:132

(cmd)
2800 | step_into > break/ok
2800 | file:///home/username/public_html/vendor/ratchet/rfc6455/src/Messaging/MessageBuffer.php:251

(cmd)
2801 | step_into > break/ok
2801 | file:///home/username/public_html/vendor/ratchet/rfc6455/src/Messaging/MessageBuffer.php:252

(cmd)
2802 | step_into > break/ok
2802 | file:///home/username/public_html/vendor/ratchet/rfc6455/src/Messaging/MessageBuffer.php:254

(cmd)
2803 | step_into > break/ok
2803 | file:///home/username/public_html/vendor/ratchet/rfc6455/src/Handshake/PermessageDeflateOptions.php:167

(cmd)
2804 | step_into > break/ok
2804 | file:///home/username/public_html/vendor/ratchet/rfc6455/src/Messaging/MessageBuffer.php:258

(cmd)
2805 | step_into > break/ok
2805 | file:///home/username/public_html/vendor/ratchet/rfc6455/src/Messaging/MessageBuffer.php:195

(cmd)
2806 | step_into > break/ok
2806 | file:///home/username/public_html/vendor/ratchet/rfc6455/src/Messaging/MessageBuffer.php:198

(cmd)
2807 | step_into > break/ok
2807 | file:///home/username/public_html/vendor/ratchet/rfc6455/src/Messaging/MessageBuffer.php:199

(cmd)
2808 | step_into > break/ok
2808 | file:///home/username/public_html/vendor/cboden/ratchet/src/Ratchet/WebSocket/WsServer.php:154

(cmd)
2809 | step_into > break/ok
2809 | file:///home/username/public_html/vendor/cboden/ratchet/src/Ratchet/Http/HttpServer.php:55

(cmd)
2810 | step_into > break/ok
2810 | file:///home/username/public_html/vendor/cboden/ratchet/src/Ratchet/Server/IoServer.php:116

(cmd)
2811 | step_into > break/ok
2811 | file:///home/username/public_html/vendor/cboden/ratchet/src/Ratchet/Server/IoServer.php:96

(cmd)
2812 | step_into > break/ok
2812 | file:///home/username/public_html/vendor/evenement/evenement/src/Evenement/EventEmitterTrait.php:127

(cmd)
2813 | step_into > break/ok
2813 | file:///home/username/public_html/vendor/evenement/evenement/src/Evenement/EventEmitterTrait.php:134

(cmd)
2814 | step_into > break/ok
2814 | file:///home/username/public_html/vendor/react/stream/src/Util.php:72

(cmd)
2815 | step_into > break/ok
2815 | file:///home/username/public_html/vendor/evenement/evenement/src/Evenement/EventEmitterTrait.php:127

(cmd)
2816 | step_into > break/ok
2816 | file:///home/username/public_html/vendor/evenement/evenement/src/Evenement/EventEmitterTrait.php:134

(cmd)
2817 | step_into > break/ok
2817 | file:///home/username/public_html/vendor/react/stream/src/DuplexResourceStream.php:202

(cmd)
2818 | step_into > break/ok
2818 | file:///home/username/public_html/vendor/react/event-loop/src/ExtEvLoop.php:97

(cmd)
2819 | step_into > break/ok
2819 | file:///home/username/public_html/vendor/react/event-loop/src/ExtEvLoop.php:96

(cmd)
2820 | step_into > break/ok
2820 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:118

(cmd)
2821 | step_into > break/ok
2821 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:119

(cmd)
2822 | step_into > break/ok
2822 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:123

(cmd)
2823 | step_into > break/ok
2823 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:124

(cmd)
2824 | step_into > break/ok
2824 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:129

(cmd)
2825 | step_into > break/ok
2825 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:139

(cmd)
2826 | step_into > break/ok
2826 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:146

(cmd)
2827 | step_into > break/ok
2827 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:147

(cmd)
2828 | step_into > break/ok
2828 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:150

(cmd)
2829 | step_into > break/ok
2829 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:155

(cmd)
2830 | step_into > break/ok
2830 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:167

(cmd)
2831 | step_into > break/ok
2831 | file:///home/username/public_html/vendor/react/event-loop/src/ExtEvLoop.php:97

(cmd)
2832 | step_into > break/ok
2832 | file:///home/username/public_html/vendor/react/event-loop/src/ExtEvLoop.php:192

(cmd)
2833 | step_into > break/ok
2833 | file:///home/username/public_html/vendor/react/event-loop/src/Tick/FutureTickQueue.php:42

(cmd)
2834 | step_into > break/ok
2834 | file:///home/username/public_html/vendor/react/event-loop/src/Tick/FutureTickQueue.php:44

(cmd)
2835 | step_into > break/ok
2835 | file:///home/username/public_html/vendor/react/event-loop/src/Tick/FutureTickQueue.php:49

(cmd)
2836 | step_into > break/ok
2836 | file:///home/username/public_html/vendor/react/event-loop/src/ExtEvLoop.php:194

(cmd)
2837 | step_into > break/ok
2837 | file:///home/username/public_html/vendor/react/event-loop/src/Tick/FutureTickQueue.php:58

(cmd)
2838 | step_into > break/ok
2838 | file:///home/username/public_html/vendor/react/event-loop/src/ExtEvLoop.php:195

(cmd)
2839 | step_into > break/ok
2839 | file:///home/username/public_html/vendor/react/event-loop/src/ExtEvLoop.php:196

(cmd)
2840 | step_into > break/ok
2840 | file:///home/username/public_html/vendor/react/event-loop/src/ExtEvLoop.php:201

(cmd)
2841 | step_into > break/ok
2841 | file:///home/username/public_html/vendor/react/event-loop/src/ExtEvLoop.php:202

(cmd)
2842 | step_into > break/ok
2842 | file:///home/username/public_html/vendor/react/event-loop/src/ExtEvLoop.php:208

(cmd)
2843 | step_into > break/ok
2843 | file:///home/username/public_html/vendor/react/event-loop/src/ExtEvLoop.php:162

(cmd)
2844 | step_into > break/ok
2844 | file:///home/username/public_html/vendor/react/event-loop/src/Timer/Timer.php:48

(cmd)
2845 | step_into > break/ok
2845 | file:///home/username/public_html/vendor/cboden/ratchet/src/Ratchet/WebSocket/WsServer.php:210

(cmd)
2846 | step_into > break/ok
2846 | file:///home/username/public_html/vendor/cboden/ratchet/src/Ratchet/WebSocket/WsServer.php:211

(cmd)
2847 | step_into > break/ok
2847 | file:///home/username/public_html/vendor/cboden/ratchet/src/Ratchet/WebSocket/WsConnection.php:31

(cmd)
2848 | step_into > break/ok
2848 | file:///home/username/public_html/vendor/cboden/ratchet/src/Ratchet/AbstractConnectionDecorator.php:31

(cmd)
2849 | step_into > break/ok
2849 | file:///home/username/public_html/vendor/cboden/ratchet/src/Ratchet/WebSocket/WsConnection.php:32

(cmd)
2850 | step_into > break/ok
2850 | file:///home/username/public_html/vendor/cboden/ratchet/src/Ratchet/WebSocket/WsServer.php:213

(cmd)
2851 | step_into > break/ok
2851 | file:///home/username/public_html/vendor/cboden/ratchet/src/Ratchet/WebSocket/WsServer.php:215

xdebug and strace with this breakpoints:
breakpoint_set -t line -f file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php -n 129
breakpoint_set -t line -f file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php -n 139

strace

write(123, "\27\3\3\0\25\17y\225\267n\303=\271\340\225K\220\354H\317\3624<z\270\233", 26) = 26
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 332) = 332
write(133, "348\0<?xml version=\"1.0\" encoding"..., 353) = 353
recvfrom(133, "run -i 2781\0", 128, 0, NULL, NULL) = 12
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- run -i"..., 38) = 38
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 332) = 332
write(133, "348\0<?xml version=\"1.0\" encoding"..., 353) = 353
recvfrom(133, "run -i 2782\0", 128, 0, NULL, NULL) = 12
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- run -i"..., 38) = 38
shutdown(123, SHUT_RDWR)                = 0
fcntl(123, F_GETFL)                     = 0x802 (flags O_RDWR|O_NONBLOCK)
fcntl(123, F_SETFL, O_RDWR|O_NONBLOCK)  = 0
write(123, "\27\3\3\0\23\324\360>\2\252\314\2341\301\204v\177\341\324!\23\320\34>", 24) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=1707488, si_uid=0} ---
close(123)                              = 0
write(122, "\27\3\3\0\25\270\313\315\34\\j\216\30\260)\1\16\357{\335bs\2\230\233\"", 26) = 26
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 332) = 332
write(133, "348\0<?xml version=\"1.0\" encoding"..., 353) = 353
recvfrom(133, "run -i 2783\0", 128, 0, NULL, NULL) = 12
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- run -i"..., 38) = 38
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 332) = 332
write(133, "348\0<?xml version=\"1.0\" encoding"..., 353) = 353
recvfrom(133, "run -i 2784\0", 128, 0, NULL, NULL) = 12
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- run -i"..., 38) = 38
shutdown(122, SHUT_RDWR)                = 0
fcntl(122, F_GETFL)                     = 0x802 (flags O_RDWR|O_NONBLOCK)
fcntl(122, F_SETFL, O_RDWR|O_NONBLOCK)  = 0
write(122, "\27\3\3\0\23g\341\261\265\234\277\267\330\341\341\200\7\303K\333\24?\37\340", 24) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=1707488, si_uid=0} ---
close(122)                              = 0
write(121, "\27\3\3\0\25\267F3\361\303\25\326\351\255\211\210\236<Q\236\254n\245\270D\256", 26) = 26
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 332) = 332
write(133, "348\0<?xml version=\"1.0\" encoding"..., 353) = 353
recvfrom(133, "run -i 2785\0", 128, 0, NULL, NULL) = 12
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- run -i"..., 38) = 38
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 332) = 332
write(133, "348\0<?xml version=\"1.0\" encoding"..., 353) = 353
recvfrom(133, "run -i 2786\0", 128, 0, NULL, NULL) = 12
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- run -i"..., 38) = 38
shutdown(121, SHUT_RDWR)                = 0
fcntl(121, F_GETFL)                     = 0x802 (flags O_RDWR|O_NONBLOCK)
fcntl(121, F_SETFL, O_RDWR|O_NONBLOCK)  = 0
write(121, "\27\3\3\0\23mV\0275\16j|+\17bR\217\36R\215\240y\225\215", 24) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=1707488, si_uid=0} ---
close(121)                              = 0
write(120, "\27\3\3\0\25$\267\317\202\204F\2\353\20\311\177\220\257\227+p2|.\276\30", 26) = 26
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 332) = 332
write(133, "348\0<?xml version=\"1.0\" encoding"..., 353) = 353
recvfrom(133, "run -i 2787\0", 128, 0, NULL, NULL) = 12
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- run -i"..., 38) = 38
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 332) = 332
write(133, "348\0<?xml version=\"1.0\" encoding"..., 353) = 353
recvfrom(133, "run -i 2788\0", 128, 0, NULL, NULL) = 12
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- run -i"..., 38) = 38
shutdown(120, SHUT_RDWR)                = 0
fcntl(120, F_GETFL)                     = 0x802 (flags O_RDWR|O_NONBLOCK)
fcntl(120, F_SETFL, O_RDWR|O_NONBLOCK)  = 0
write(120, "\27\3\3\0\0236=\362!\336\304\16\357\271\10QQ.S\210V2M\5", 24) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=1707488, si_uid=0} ---
close(120)                              = 0
write(119, "\27\3\3\0\25\225\336\340\374\257\351\212\225&\307\276\271\233=\223`\256\246|\32L", 26) = 26
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 332) = 332
write(133, "348\0<?xml version=\"1.0\" encoding"..., 353) = 353
recvfrom(133, "run -i 2789\0", 128, 0, NULL, NULL) = 12
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- run -i"..., 38) = 38
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 332) = 332
write(133, "348\0<?xml version=\"1.0\" encoding"..., 353) = 353
recvfrom(133, "run -i 2790\0", 128, 0, NULL, NULL) = 12
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- run -i"..., 38) = 38
shutdown(119, SHUT_RDWR)                = 0
fcntl(119, F_GETFL)                     = 0x802 (flags O_RDWR|O_NONBLOCK)
fcntl(119, F_SETFL, O_RDWR|O_NONBLOCK)  = 0
write(119, "\27\3\3\0\23\335 \3728\374\320\241\313\207\216H\371?] 6B\2561", 24) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=1707488, si_uid=0} ---
close(119)                              = 0
write(118, "\27\3\3\0\25B\307\223d\312\337\263\354\241\375\312\"\353&\354d\17\370\355\"\220", 26) = 26
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 332) = 332
write(133, "348\0<?xml version=\"1.0\" encoding"..., 353) = 353
recvfrom(133, "run -i 2791\0", 128, 0, NULL, NULL) = 12
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- run -i"..., 38) = 38

xdebug

(cmd)
2781 | run > break/ok
2781 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:139

(cmd)
2782 | run > break/ok
2782 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:129

(cmd)
2783 | run > break/ok
2783 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:139

(cmd)
2784 | run > break/ok
2784 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:129

(cmd)
2785 | run > break/ok
2785 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:139

(cmd)
2786 | run > break/ok
2786 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:129

(cmd)
2787 | run > break/ok
2787 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:139

(cmd)
2788 | run > break/ok
2788 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:129

(cmd)
2789 | run > break/ok
2789 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:139

(cmd)
2790 | run > break/ok
2790 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:129

(cmd)
2791 | run > break/ok
2791 | file:///home/username/public_html/vendor/react/stream/src/WritableResourceStream.php:139

I also have this in strace, but I don't know if it is important.
strace

write(4, "[1707488] [Step Debug] -> <respo"..., 336) = 336
write(133, "352\0<?xml version=\"1.0\" encoding"..., 357) = 357
recvfrom(133, "step_into -i 2340\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 336) = 336
write(133, "352\0<?xml version=\"1.0\" encoding"..., 357) = 357
recvfrom(133, "step_into -i 2341\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
poll([{fd=55, events=POLLIN|POLLPRI|POLLERR|POLLHUP}], 1, 0) = 1 ([{fd=55, revents=POLLIN}])
read(55, "\27\3\3\0U", 5)               = 5
read(55, "i\300\311CW\7\221]\202G\21\273nz\357\26\377D2-\36\315\343`\223/2\345+s\f\272"..., 85) = 85
poll([{fd=55, events=POLLIN|POLLPRI|POLLERR|POLLHUP}], 1, 0) = 1 ([{fd=55, revents=POLLIN}])
read(55, "\27\3\3\0\272", 5)            = 5
read(55, "\17\246\240\217SATUw8\376\21\336\342i\376\213Us\253\261\357\3\216\233\365\326\257\246wN-"..., 186) = 186
poll([{fd=55, events=POLLIN|POLLPRI|POLLERR|POLLHUP}], 1, 0) = 0 (Timeout)
read(55, 0x5605808a0be3, 5)             = -1 EAGAIN (Resource temporarily unavailable)
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 336) = 336
write(133, "352\0<?xml version=\"1.0\" encoding"..., 357) = 357
recvfrom(133, "step_into -i 2342\0", 128, 0, NULL, NULL) = 18
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] <- step_i"..., 44) = 44
getpid()                                = 1707488
write(4, "[1707488] [Step Debug] -> <respo"..., 336) = 336
write(133, "352\0<?xml version=\"1.0\" encoding"..., 357) = 357
recvfrom(133, "step_into -i 2343\0", 128, 0, NULL, NULL) = 18
getpid()

xdebug

(cmd)
2340 | step_into > break/ok
2340 | file:///home/username/public_html/vendor/react/stream/src/DuplexResourceStream.php:185

(cmd)
2341 | step_into > break/ok
2341 | file:///home/username/public_html/vendor/react/stream/src/DuplexResourceStream.php:187

(cmd)
2342 | step_into > break/ok
2342 | file:///home/username/public_html/vendor/react/stream/src/DuplexResourceStream.php:189

(cmd)
2343 | step_into > break/ok
2343 | file:///home/username/public_html/vendor/react/stream/src/DuplexResourceStream.php:195

(cmd)
2344 | step_into > break/ok
2344 | file:///home/username/public_html/vendor/react/stream/src/DuplexResourceStream.php:196

For now I will proceed to install PHP 7.1 to see if the problem persists with this version.
Thank you for your replies.

My hunch is this has something to do resource. Are you running it on a shared host or VPS? I saw cPanel in your Apache info. Also did you try to run garbage collection on connection close?

I am running Ratchet in a VPS (AlmaLinux v8.4.0) with KVM (QEMU), in this same VPS I also have my website running with Apache
uname -a
Linux xxxx-xxxxx.server.name 4.18.0-305.19.1.el8_4.x86_64 #1 SMP Wed Sep 15 11:28:53 EDT 2021 x86_64 x86_64 x86_64 GNU/Linux

hostnamectl
   Static hostname: xxxx-xxxxx.server.name
         Icon name: computer-vm
           Chassis: vm
        Machine ID: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
           Boot ID: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
    Virtualization: kvm
  Operating System: AlmaLinux 8.4 (Electric Cheetah)
       CPE OS Name: cpe:/o:almalinux:almalinux:8.4:GA
            Kernel: Linux 4.18.0-305.19.1.el8_4.x86_64
      Architecture: x86-64

Yes, I added gc_collect_cycles(); on the end of onClose  function.
I also leave a couple of screenshots of Munin showing sudden CPU usage:

Thank for your replie.

This sort of things are really hard to track down.  Those from OVH are rather inexpensive.

Thanks for the suggestion, for now I'm going to wait, chat is a fairly secondary function in my application and at the moment it is not a big problem.
Thanks for all replies.

Hi ollm,
Have you resolved this?
I'm also having this issue with 100% CPU load.

@ollm Thanks for looking into this, this definitely shouldn't have happened! I did take a look at your strace and xdebug logs and it looks like the server may indeed be "stuck" on a "dead" connection, continuously trying to write some data on each loop tick and always getting an EPIPE/SIGPIPE in return.
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10400) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10400) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---
epoll_wait(6, [{EPOLLOUT|EPOLLHUP, {u32=144, u64=3702261809296}}], 680, 10400) = 1
epoll_ctl(6, EPOLL_CTL_MOD, 144, {EPOLLOUT, {u32=144, u64=3702261809296}}) = 0
write(144, "\27\3\3\0\25\261\3\360_\3138\365>\260H\207\321X\226\361\206\240v\326:\351", 26) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=3517427, si_uid=0} ---

(Note to self: The underlying epoll calls seem to confirm you're correctly using ExtEvLoop on a Linux-based system.)
Translating the above snippet to ReactPHP's logic means the event loop (correctly) identified this connection as writable and notified the outgoing stream to (try to) write some data which reports an error message on the syscall level (all correct for dead connections). As rightfully identified, the stream component is responsible for detecting this error condition and properly closing the socket connection in this case. For some reason, this logic doesn't seem to trigger, so the stream accepts an empty write and retries in the next loop iteration ad infinitum, thus causing 100% CPU usage.
It looks like this issue might be related to my changes introduced in https://github.com/reactphp/stream/pull/150 in response to https://github.com/reactphp/stream/pull/149. In this case, it would be helpful for further debugging if you could dump the contents of $written and $error before this line: https://github.com/reactphp/stream/blob/70d6e15d5f90730651558852c74fbb767fd9215b/src/WritableResourceStream.php#L139
We have reproducible test cases for the existing behavior and I would love to come up with a reproducible test case for your specific error. The test suite contains a number of tests for broken pipes on various platforms and before seeing this very ticket here, I would have expected this to be a non-issue. In either case, thanks for reporting this high quality ticket!

@clue this sounds very serious. Should we revert back to certain commit for production servers while you are working on this issue?

@zhiyong-ft No reason to panic. To the best of our knowledge this is a very rare error condition that does not seem to happen very often. The PRs linked above have been merged more than a year ago and we are not currently aware of any other reports running into this, despite ReactPHP being used in production in countless applications.
If this condition occurs, you will see load spikes, but the server should stay responsive otherwise (there's no crash or known DoS afaict). If you manage to run into this, please help us identify the root cause (see previous message) and I'm happy to look into this. Reverting to an old version doesn't seem sensible at this point as the previous version had other known issues (again linked in previous message) that are in turn known to be fixed in the current version.

It looks like this issue might be related to my changes introduced in https://github.com/reactphp/stream/pull/150 in response to https://github.com/reactphp/stream/pull/149. In this case, it would be helpful for further debugging if you could dump the contents of $sent and $error before this line: https://github.com/reactphp/stream/blob/70d6e15d5f90730651558852c74fbb767fd9215b/src/WritableResourceStream.php#L139

@clue I've prepared the code so that I can dump $sent and $error when the overload occurs again, but on my server it can take days/weeks until it happens (The last time was 3 days ago), so I don't know when I'll have the results.

could dump the contents of $sent and $error before this line: https://github.com/reactphp/stream/blob/70d6e15d5f90730651558852c74fbb767fd9215b/src/WritableResourceStream.php#L139

I added this line:
echo "sent  >".json_encode($sent)."< error >".json_encode($error)."<\n";
Before this line:
if (($sent === 0 || $sent === false) && $error !== null) {
The output:
sent  >0< error >null<
sent  >0< error >null<
sent  >0< error >null<
....
sent  >0< error >null<

@acadjsr Thanks for providing these details, this definitely helps us pinpoint this issue!

I added this line: echo "sent >".json_encode($sent)."< error >".json_encode($error)."<\n";
Before this line: if (($sent === 0 || $sent === false) && $error !== null) {
The output when CPU usage is 100% : sent >0< error >null<

This is interesting and confirms my suspicions that the underlying write() syscall fails and reports and error, however PHP's fwrite() function doesn't actually report an error in this case. Because PHP doesn't report an error to us, our logic fails and assumes the stream is still valid, thus ending up repeatedly retrying to write data, until the stream is closed some other way (timeouts or process restarts).
I've looked into this and have some ideas how this could be addressed, but still have a hard time trying to come up with a reproducible test case for this scenario. It looks like you've been able to reproduce this quite easily, so perhaps you can help us figure out how to repeat this process?
From my understanding this logic triggers only in this specific case:

trying to write data to a connection that is already closed on the remote side (see EPIPE error) and
reading from the connection is paused (event loop only reports stream as writable and doesn't check for readability, possible due to end() call?) and
encrypted TLS connections (see binary data header and syscall write() vs sendto()) and
some other unknown condition?

We do in fact have tests for this specific scenario in place and so far I'm unable to reproduce this locally. So that leaves me wondering what's the missing piece here?

I can not reproduce it.
It is occurring in my production server every 2 days or sooner.

trying to write data to a connection that is already closed on the remote side (see EPIPE error) and

@clue do you have a way to make a connection close on client side but not on server? My experience is this is not easy to accomplish. WS test clients like the plugin for Chrome will always gracefully close open connections between shut down. One way would be to either kill the test client process or unplug the power of computer test client is running on.
Even you are familiar with embedded system, I can also provide a embedded ws client, it is a lot easier and faster to ungracefully shut down a client and then start again.

a kill -9 could do the trick

@WyriHaximus is this command for Linux? End task in task manager on Windows 11 doesn't work. Connection on server will still be closed(presumably requested by OS). So far the only reliable way on my hands is power off my embedded system.

@zhiyong-ft That's for Linux, that will kill the process hard without giving it time to clean up. Which hopefully has the same effect as powering off your embedded system by pulling the plug

These are the values of $send and $error when the process is at 100% CPU, they are the same values as @acadjsr
$sent: int(0)
$error: NULL

$sent: int(0)
$error: NULL

$sent: int(0)
$error: NULL

I've tried to kill the local websocket created with wsstat or wscat, but I can't reproduce the error in the server, I've also tried to disconnect the network connection while the websocket in the browser is connected (Also wsstat and wscat), but it doesn't work either.

Bummer, looking for a way to reproduce this with software, without the need to hard pull a device.

I think sockets are most likely managed by OS itself. Once a process that uses a socket is killed, OS will just close underlining socket by default.
@WyriHaximus see if you can get some embedded system, such as those STM32 nucleo boards. I will be happy to help you guys setup a test client. You push a button to reset the embedded system, now you have a orphan connection on your server.
Or you can send me you ws/wss URL, I can connect to your server and reset.
Bottomline, I am more than happy to help you guys test and fix this. Having such issue wakes me up in the middle of night.

trying to write data to a connection that is already closed on the remote side (see EPIPE error) and

@clue do you have a way to make a connection close on client side but not on server? My experience is this is not easy to accomplish. WS test clients like the plugin for Chrome will always gracefully close open connections before shut down. One way would be to either kill the test client process or unplug the power of computer test client is running on.

@zhiyong-ft Just to be clear, are you saying you can reproduce this error condition consistently by forcefully closing the client connection (i.e. disconnecting without a proper socket shutdown / sending FIN)?

@clue I can reliably turn off ws client while keeping socket open on server side for several hours. I didn't try to reproduce the issue itself. Don't have the brain bandwidth at the moment. Have been pulling all nights on some other stuff :)

@clue I can reliably turn off ws client while keeping socket open on server side for several hours. I didn't try to reproduce the issue itself.

@zhiyong-ft I'm not sure I follow exactly what you're trying to achieve, but it sounds like this would be unrelated to this ticket. If you're seeing any other error or have any other questions, perhaps it makes sense to file this as a separate ticket?

@clue actually I think it is relevant. You mentioned that having a connection/socket open on server side but closed on client side is a requirement for this issue to happen. From my experience, this(socket open on server side but closed on client side) is easy to achieve on most common setup. @WyriHaximus thought he could do it by forcefully close client process, but that actually doesn't achieve this. Essentially, what I am trying to offer is a way to help reproduce the issue, not an issue itself therefore doesn't warrant a separate ticket.

I put this code to capture what is being written in this case. Will let you know when this occur.
        if (($sent == 0) && ($error == null))
        {
            $this->emit('error', array(new \RuntimeException("DEBUG: Unable to write to stream with data = '" . json_encode($this->data) . "' and writeChunkSize = '" . json_encode($this->writeChunkSize) . "'")));
        }

@clue actually I think it is relevant. You mentioned that having a connection/socket open on server side but closed on client side is a requirement for this issue to happen. From my experience, this(socket open on server side but closed on client side) is not easy to achieve on most common setup, hence the issue doesn't happen that often. […]

@zhiyong-ft I think you might have misread me and I don't currently see how this would be related to the issue. A client that closes the connection is a pretty normal thing and the fact that the server detects this some time later is part of normal operation. This is also covered by our automated test suite and covered by years of production use of ReactPHP, so we're not aware of any issues in this regard.

From my understanding this logic triggers only in this specific case:

trying to write data to a connection that is already closed on the remote side (see EPIPE error) and

reading from the connection is paused (event loop only reports stream as writable and doesn't check for readability, possible due to end() call?) and

encrypted TLS connections (see binary data header and syscall write() vs sendto()) and

some other unknown condition?

Self-quoting here to emphasize the first point is not problematic, but also not too common. Usually, a client connection would be readable at all times, so the server would detect a disconnect as an empty read and then trigger a close event automatically. The above debugging output suggests the client is not in a readable state however. This is not problematic at all, but still an interesting insight because it would only be triggered by a previous pause() or end() call. This means the server has no way to detect the disconnected client until it executes the next socket operation. In this instance, the outgoing write should fail (as expected) and then trigger a close event. We have a number of test cases that verify this behavior, so again this is known to work.
However, after analyzing the above debugging output, we can see that the underlying write() reports an error (expected), but PHP doesn't report this error to us (unexpected). As a result, our logic keeps retrying and thus causing high CPU load. We have yet to figure out what is causing this behavior. Once we have a better understanding of this situation, a permanent fix should be rather straight forward.
If you can see unreasonably high CPU usage and have a way to reproduce this (even if it doesn't happen 100% and no matter how complex this setup might be), by all means, please report back and I'm happy to help track down the underlying issue.

I put this code to capture what is being written in this case. Will let you know when this occur.
        if (($sent == 0) && ($error == null))
        {
            $this->emit('error', array(new \RuntimeException("DEBUG: Unable to write to stream with data = '" . json_encode($this->data) . "' and writeChunkSize = '" . json_encode($this->writeChunkSize) . "'")));
        }

This has occurred. Here is the output:
2022/04/22 05:58:31 - An error has occurred: DEBUG: Unable to write to stream with data = '' and writeChunkSize = '-1'
So it seems that the $this->data is empty string so $sent is zero. No error has occurred.

After above has occurred I changed the code to capture if data is ''. Like this:
        if (($sent == 0) && ($error == null))
        {
            $this->emit('error', array(new \RuntimeException("DEBUG: Unable to write to stream with data = '" . json_encode($this->data) . "' and writeChunkSize = '" . json_encode($this->writeChunkSize) . "' where data === '' is ".(($this->data === '') ? "true" : "false")." and data == '' is ".(($this->data == '') ? "true" : "false"))));
        }

Here are the results, (note the bold):
2022/04/23 22:47:37 - An error has occurred: DEBUG: Unable to write to stream with data = '' and writeChunkSize = '-1' where data === '' is false and data == '' is false
So the issue is that the data is not a string or empty string so bellow code never occur.
if ($this->data === '') {
...
}

@clue thanks for taking the time to explain, I don't fully understand the issue so I will take your word. Hopefully my comments were not distracting.

@zhiyong-ft Dont worry. Please report back if this turns out to be related to this issue and I'm happy to look into this again!

So it seems that $this->data is empty string so $sent is zero. No error has occurred.
[…]
2022/04/23 22:47:37 - An error has occurred: DEBUG: Unable to write to stream with data = '' and writeChunkSize = '-1' where data === '' is false and data == '' is false

@acadjsr It looks like this might be related to how you're using json_encode() which might return a (bool) false which would then cast to an (string) "". This happens if the data can not be encoded (in particular for binary data). Can you update this to use JSON_INVALID_UTF8_SUBSTITUTE or bin2hex() or base64_encode()? The output of stream_get_meta_data() and feof() might also be interesting.

And with JSON_INVALID_UTF8_SUBSTITUTE I get
Error Exception: Unable to write to stream with data = '"\ufffd\u0002\u0003\ufffd"' and writeChunkSize = '-1'

I am also experiencing this problem, but CPU load is fine. Not sure if related.

@TechOverflow I don't think this is related, as this specific instance here deals with high CPU load due to failing writes on the socket layer. Can you file your problem as a separate ticket? Thank you.

Hi @clue, Yes it was a mistake in my code. Sorry for the clutter.

I have the same problem with CPU usage. Happens mostly when hundreds of participants are active throughout the day.

I can confirm, with this code no problems so far anymore (without the "$error !== null" check):
if ($sent === 0 || $sent === false) {
$this->emit('error', array(new \RuntimeException('Unable to write to stream: ' . $error)));
$this->close();
return;

}
Is "$sent === false" the only error possibility here or the same as "$error !== null".
Is there any known drawbacks, when i close the connection if 0 bytes written? Shouldn't really happen normally, right?

So it seems that $this->data is empty string so $sent is zero. No error has occurred.
[…]
2022/04/23 22:47:37 - An error has occurred: DEBUG: Unable to write to stream with data = '' and writeChunkSize = '-1' where data === '' is false and data == '' is false

@acadjsr It looks like this might be related to how you're using json_encode() which might return a (bool) false which would then cast to an (string) "". This happens if the data can not be encoded (in particular for binary data). Can you update this to use JSON_INVALID_UTF8_SUBSTITUTE or bin2hex() or base64_encode()? The output of stream_get_meta_data() and feof() might also be interesting.

I have the javascript code (that executes in user browser) that checks for disconnected websocket and tries to connect if disconnected.
A week ago I changed it to do this only when page is visible and I did not had this error for a week.
if (document.visibilityState === 'visible')

I figured out that something is wrong, I never had this long period without an error. So last night I reverted it back like it was and sure enough this morning I had 3 errors "Unable to write to stream" waiting for me. All 3 are the same.
So here is the error output:
==========================
gettype: string
mb_detect_encoding:
strlen: 4

Warning: mb_strlen(): Unknown encoding "" in ***************************/vendor/react/stream/src/WritableResourceStream.php on line 145
mb_strlen:
bin2hex: 880203e8
base64_encode: iAID6A==
stream_get_meta_data: {"crypto":{"protocol":"UNKNOWN","cipher_name":"TLS_AES_256_GCM_SHA384","cipher_bits":256,"cipher_version":"TLSv1.3"},"timed_out":false,"blocked":false,"eof":true,"stream_type":"tcp_socket\/ssl","mode":"r+","unread_bytes":0,"seekable":false}
feof: true
2022/05/02 02:04:35 - An error has occurred: DEBUG: Unable to write to stream with data = '"\ufffd\u0002\u0003\ufffd"' and writeChunkSize = '-1' where data === '' is false and data == '' is false

==========================

Here is the code:
        if (($sent == 0) && ($error == null))
        {
            echo "\n\n\n==========================\n";
            echo "gettype: ".gettype($this->data)."\n";
            if (gettype($this->data) == "string")
            {
                echo "mb_detect_encoding: ".mb_detect_encoding($this->data)."\n";
                echo "strlen: ".strlen($this->data)."\n";
                echo "mb_strlen: ".mb_strlen($this->data, mb_detect_encoding($this->data))."\n";
            }
            echo "bin2hex: ".bin2hex($this->data)."\n";
            echo "base64_encode: ".base64_encode($this->data)."\n";
            $meta = \stream_get_meta_data($this->stream);
            echo "stream_get_meta_data: ".json_encode($meta, JSON_INVALID_UTF8_SUBSTITUTE)."\n";
            echo "feof: ".json_encode(\feof($this->stream))."\n";
            $this->emit('error', array(new \RuntimeException("DEBUG: Unable to write to stream with data = '" . json_encode($this->data, JSON_INVALID_UTF8_SUBSTITUTE) . "' and writeChunkSize = '" . json_encode($this->writeChunkSize) . "' where data === '' is ".(($this->data === '') ? "true" : "false")." and data == '' is ".(($this->data == '') ? "true" : "false"))));
            echo "\n==========================\n";
        }

[…] So here is the error output:

@acadjsr Thank you very much, this definitely helps tracking this down!

feof: true

This is good news because this suggests we should be able to detect this error condition quite easily. While the underlying syscall reports an error when writing to a closed stream (expected), PHP doesn't report this error to us (unexpected), but PHP at least reports the stream as closed. This means that inside ReactPHP we should be able to raise an error manually in this case and gracefully close the local side of the connection as well.

bin2hex: 880203e8

This is interesting because it suggests the server is trying to send a normal close message to the client (OP_CLOSE = 8 with CLOSE_NORMAL = 1000). This also seems to be in line with everything that's been reported as part of this ticket so far.

I figured out that something is wrong, I never had this long period without an error. So last night I reverted it back like it was and sure enough this morning I had 3 errors "Unable to write to stream" waiting for me

Interesting! With the above debugging, it looks like this might indeed be related to connections that are about to close. It's currently my understanding the client is closing the connection by informing the server which in turn wants to send a close frame to the client which is no longer possible at this point. The server should detect this situation and abort the outgoing write and just consider the connection dead at this point, but for seem reason ends up in a loop because PHP doesn't report the write as failing. The above debugging output also suggests this only happens for TLS connections and probably works just fine for plaintext connections.
I'm still trying to find an easy way to reproduce this locally to make sure a possible patch fixes this once and for all. Does the above help reproduce the problem?

I can not reproduce this.

We are experiencing the same problem

there is nothing else that stands out. no errors or anything like that. the server continues to accept connections
Operating System: Debian GNU/Linux 11 (bullseye)
PHP: PHP 7.4.28 (cli) (built: Feb 17 2022 16:17:19)
Loop: object(React\EventLoop\ExtEvLoop)

I fixed this by reverting this commit: https://github.com/reactphp/stream/pull/150/commits/3eb342d87ca89e0c4c7c428505f36051c172f677

Can anybody confirm this? I don't have enough understanding of reactphp for this. we would like to use ratchet productively... but at the moment we have to restart the server 2-3 times a day
what do I have to do to test what @acadjsr wrote? replace the green-lines (right) with the red-lines (right)?

I fixed this by reverting this commit: reactphp/stream@3eb342d

@acadjsr Reverting to an old version doesn't seem sensible at this point as the previous version had other known issues that are in turn known to be fixed in the current version (see above https://github.com/ratchetphp/Ratchet/issues/939#issuecomment-1098798274).

Can anybody confirm this? […]

@fx1234 This may fix this specific error but may cause other issues (see above), so I do not recommend this for production use. Perhaps you can help us pinpoint this issue instead.
I'm still trying to find an easy way to reproduce this locally to make sure a possible patch fixes this once and for all. Can anybody reliably reproduce the problem so far with the above instructions?

Unfortunately I don't think I can be of any help here.
I don't see any pattern. Sometimes it happens after 12 hours, sometimes after 30 minutes. Sometimes 1000+ clients are connected, sometimes it's only 100

I fixed this by reverting this commit: reactphp/stream@3eb342d

@acadjsr Reverting to an old version doesn't seem sensible at this point as the previous version had other known issues that are in turn known to be fixed in the current version (see above #939 (comment)).

I missed to mention that I reverted only this file: WritableResourceStream.php
So I'm not having this issue for 4 weeks.

We made the changes as suggested by @acadjsr and this is the first time we haven't had to restart the server in over 24 hours.
So the problem is definitely to be found there

@fx1234 @acadjsr what do you see in system logs when high CPU usage happens?
One of my dev server that runs rachet somehow started to have high CPU usage (50%, 1 core out of two completely used), and high ram usage (near 100%), not responding to remote SSH connection request. In kern.log I see an entry with many NULL with timestamp cooresponding to high usage of CPU/RAM.
At this point I am not sure this is caused by rachet, but rachet is the only service on this server. Is there any way to rule out?
Thanks.

I don't know. It did not happen even once in last 5 months in production after the solution:
https://github.com/ratchetphp/Ratchet/issues/939#issuecomment-1132159140

@acadjsr Thanks for the information. I think I too will apply the fix before putting it into production.
When high CPU issue happened, were you able to log in via SSH? Were other service such as Apache still responsive?

The same for me as for @acadjsr. I think the PHP process was at 100%, but I can't tell exactly

@acadjsr Thanks for the information. I think I too will apply the fix before putting it into production.
When high CPU issue happened, were you able to log in via SSH? Were other service such as Apache still responsive?

I was able to login in via SSH. Other services are still responsive.

I'm really struggling with this issue too. Randomly (it seems) every 3 days to a month PHP consumes an entire CPU core (running Ratchet/ReactPHP). strace shows:
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=995813, si_uid=1000} ---
pselect6(91, [5 7 15 36 45], [90], [], {tv_sec=29, tv_nsec=604598000}, NULL) = 1 (out [90], left {tv_sec=29, tv_nsec=604596023})
write(90, "\313\301\20$\226RuKn\263\241\336\30\234\2271\177\220K\21\v\340\245<r\7\355\261\237\26\rG"..., 3190) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=995813, si_uid=1000} ---
pselect6(91, [5 7 15 36 45], [90], [], {tv_sec=29, tv_nsec=604355000}, NULL) = 1 (out [90], left {tv_sec=29, tv_nsec=604353252})
write(90, "\313\301\20$\226RuKn\263\241\336\30\234\2271\177\220K\21\v\340\245<r\7\355\261\237\26\rG"..., 3190) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=995813, si_uid=1000} ---
pselect6(91, [5 7 15 36 45], [90], [], {tv_sec=29, tv_nsec=604117000}, NULL) = 1 (out [90], left {tv_sec=29, tv_nsec=604115286})
write(90, "\313\301\20$\226RuKn\263\241\336\30\234\2271\177\220K\21\v\340\245<r\7\355\261\237\26\rG"..., 3190) = -1 EPIPE (Broken pipe)

I can never tie this down to any event in my application's log.
The websocket server application is still working while this happens but it is very slow to respond. The only solution is a restart of the Ratchet process, which is highly disruptive.

Have you tried to revert this commit:
https://github.com/reactphp/stream/commit/3eb342d87ca89e0c4c7c428505f36051c172f677
My Ratchet is rock solid and never failed (for more than a year) after the revert.

Thanks @acadjsr I'll give it a go

@clint0s Thanks for the additional input on this :+1:
Still working together with @clue on a solution for this, already spent multiple hours and we have yet to figure out a way to reproduce this issue.
Also note @clue's comment about reverting to an old version above:

Reverting to an old version doesn't seem sensible at this point as the previous version had other known issues that are in turn known to be fixed in the current version (see above https://github.com/ratchetphp/Ratchet/issues/939#issuecomment-1098798274).


Target Validation: Subdomains with a hyphen aren't considered valid

The regex used for target validation is defined here:
https://github.com/checktheroads/hyperglass/blob/c25cc5f3e13272b0534051e5a09614f852e2211c/hyperglass/ui/components/QueryTarget.js#L5
Example of domains that fails the validation:

r3.sn-fpoq-o52l.googlevideo.com
speedtest-mi1.cloudfire.it

I think the following regex should fix the bug:
/^(?!:\/\/)([a-zA-Z0-9][a-zA-Z0-9-]+\.)?[a-zA-Z0-9][a-zA-Z0-9-]+\.[a-zA-Z]{2,6}?$/gim

Good catch! This will be fixed in the next release.


Add test code for sending delete and backspace keys

Change list
Added a test for sending delete keys to a text edit
Added a test for sending backspace keys to a text edit
Updated the YouiEngine sample app
Types of changes

[x] New feature (non-breaking change which adds functionality)

Details
Updated the YouiEngine sample app and added tests.

make sure you run mvn clean site
https://github.com/appium/java-client/blob/master/docs/Note-for-developers.md#code-style

Does this include the AEP changes you mentioned earlier? About moving some of the views off to a different page?

mvn clean site
BUILD SUCCESS

+1


Creating a new policy with the same ID as an existing policy "merges" them

Reported by a user.

I tried to create a read policy but somehow instead of a new policy, the change is merged to an existing policy.
[...]
Thanks, I figured it out. I used GUI. I gave a new policy name, but in the JSON I copied, I forget to change the policy id, then lakeFS “smartly” merge it to existing policy instead of creating a new one.

(Emphasis mine)

This is already fixed by #4355
Closing this issue.


Fix IA-1687 Feature flag dropdown on edit Project dialog is sometime empty

Fix race condiition between the dialog and the network.
Self proof reading checklist

[x] Did I use eslint and black formatters
[x] Is my code clear enough and well documented
[x] Are my typescript files well typed
[NA] Did I add translations
[NA] My migrations file are included
[?] Are there enough tests

Changes
This seems to be caused by a race condition. Between fetching the feature flag list and the dialog generation.
If columns() is called with an empty FeatureFlag it is not updated afterward.
Fixed it by moving the useGetFeatureFlags call to the Dialog itself. Ideally we should in the future move the dialog to the new system so it only make the query when opened.
Also added a loading state on the Input to show it's fetching data.
And added Memo and some more robustness.
How to test
It was a race condition so the error didn't always happen before.
To reproduce

Go to the project page.
Edit an existing project
Go to the feature flag tab
open the dropdown

To help reproduce locally, you can add a waitFor in the query in useGetFeatureFlags.
--- a/hat/assets/js/apps/Iaso/domains/projects/hooks/requests.ts
+++ b/hat/assets/js/apps/Iaso/domains/projects/hooks/requests.ts
@@ -5,6 +5,7 @@ import { useSnackQuery, useSnackMutation } from '../../../libs/apiHooks';
 import { PaginatedProjects } from '../types/paginatedProjects';
 import { FeatureFlag } from '../types/featureFlag';
 import { UrlParams, ApiParams } from '../../../types/table';
+import { waitFor } from '../../../utils';

 export const useGetProjectsPaginated = (
     params: UrlParams,
@@ -33,7 +34,7 @@ export const useGetFeatureFlags = (): UseQueryResult<
     // @ts-ignore
     return useSnackQuery(
         ['featureflags'],
-        () => getRequest('/api/featureflags/'),
+        () => waitFor(20000).then(() => getRequest('/api/featureflags/')),
         undefined,
         {
             // using this here to avoid multiple identical calls

@cypress


New version: Mozilla.Firefox.DeveloperEdition.an version 132.0 (132.0b4)

Created by 🥟 Dumplings.
Microsoft Reviewers: Open in CodeFlow

Verify by proxy: https://github.com/microsoft/winget-pkgs/pull/179431#issuecomment-2400690391


New pods sometimes fail to retrieve container pid

When deploying example
kubectl apply -f examples/kubernetes/deployments-should-succeed.yaml

opensuse@lockc-control-plane-0:/usr/local/src/lockc/examples/kubernetes> kubectl describe pod nginx-default-64855d894f-plqmk
Name:           nginx-default-64855d894f-plqmk
Namespace:      default
Priority:       0
Node:           lockc-control-plane-0/<IP_ADDRESS>
Start Time:     Wed, 03 Nov 2021 17:27:49 +0000
Labels:         app=nginx-default
                pod-template-hash=64855d894f
Annotations:    <none>
Status:         Pending
IP:
IPs:            <none>
Controlled By:  ReplicaSet/nginx-default-64855d894f
Containers:
  nginx:
    Container ID:
    Image:          nginx:1.14.2
    Image ID:
    Port:           80/TCP
    Host Port:      0/TCP
    State:          Waiting
      Reason:       ContainerCreating
    Ready:          False
    Restart Count:  0
    Environment:    <none>
    Mounts:
      /var/run/secrets/kubernetes.io/serviceaccount from kube-api-access-2jprk (ro)
Conditions:
  Type              Status
  Initialized       True
  Ready             False
  ContainersReady   False
  PodScheduled      True
Volumes:
  kube-api-access-2jprk:
    Type:                    Projected (a volume that contains injected data from multiple sources)
    TokenExpirationSeconds:  3607
    ConfigMapName:           kube-root-ca.crt
    ConfigMapOptional:       <nil>
    DownwardAPI:             true
QoS Class:                   BestEffort
Node-Selectors:              <none>
Tolerations:                 node.kubernetes.io/not-ready:NoExecute op=Exists for 300s
                             node.kubernetes.io/unreachable:NoExecute op=Exists for 300s
Events:
  Type     Reason                  Age   From               Message
  ----     ------                  ----  ----               -------
  Normal   Scheduled               26s   default-scheduler  Successfully assigned default/nginx-default-64855d894f-plqmk to lockc-control-plane-0
  Warning  FailedCreatePodSandBox  24s   kubelet            Failed to create pod sandbox: rpc error: code = Unknown desc = failed to create containerd task: failed to retrieve OCI runtime container pid: open /run/containerd/io.containerd.runtime.v1.linux/k8s.io/a96796afd7521a26e5a40ed671db24fc13be5f773536962414919856e25dfb7b/init.pid: no such file or directory: unknown
  Warning  FailedCreatePodSandBox  13s   kubelet            Failed to create pod sandbox: rpc error: code = Unknown desc = failed to create containerd task: failed to retrieve OCI runtime container pid: open /run/containerd/io.containerd.runtime.v1.linux/k8s.io/72c09bc2f389717049d13a8c43d4d1ddb7f76d8717844a287f14be368d2c4b74/init.pid: no such file or directory: unknown

This one is the wackiest:
Events:
  Type     Reason     Age                  From               Message
  ----     ------     ----                 ----               -------
  Normal   Scheduled  36m                  default-scheduler  Successfully assigned baseline/nginx-baseline-cd5dd7669-5bptp to lockc-control-plane-0
  Normal   Pulling    36m                  kubelet            Pulling image "nginx:1.14.2"
  Normal   Pulled     36m                  kubelet            Successfully pulled image "nginx:1.14.2" in 14.484965757s
  Normal   Created    34m (x5 over 36m)    kubelet            Created container nginx
  Warning  Failed     34m (x5 over 36m)    kubelet            Error: failed to create containerd task: failed to retrieve OCI runtime container pid: open /run/containerd/io.containerd.runtime.v1.linux/k8s.io/nginx/init.pid: no such file or directory: unknown
  Normal   Pulled     34m (x4 over 36m)    kubelet            Container image "nginx:1.14.2" already present on machine
  Warning  BackOff    89s (x161 over 36m)  kubelet            Back-off restarting failed container

/run/containerd/io.containerd.runtime.v1.linux/k8s.io/nginx/init.pid? WTF? just a name without any container ID? what is even asking for such a path? :/


Sizes of sets without sizes

content/sets-functions-relations/size-of-sets/comparing-size.tex makes use of \card to compare sizes of sets. This leads students to think \card{X} makes independent sense, ie, there's something called the "size" of a set that can be compared, added, etc.  This should be clarified.

instead of defining \card{X} \le \card{Y}, define a size-wise ordering eg X \preceq Y
add a remark that sizes (ie cardinal numbers) and an arithmetic on them can be defined but we're not defining them

Ready to be fixed via commit a6a70a4aa4a915128fe93eee1bd60d6887564861


SetInitNumProc compile error

With the following code
        vs := vssh.New()
        vs.SetInitNumProc(2)
        vs.Start()

I am getting the following output
command-line-arguments
./main.go:13:4: vs.SetInitNumProc undefined (type *vssh.VSSH has no field or method SetInitNumProc)

Thanks for reporting this issue.
It fixed. pls update the library then try again and let me know if you still has issue.


CircleCI build of documentation preview contains multiple Runtime errors

🐛 Bug
CircleCI build of documentation preview contains multiple Runtime errors. It may lead to multiple problems in the future.
To Reproduce
https://app.circleci.com/pipelines/github/napari/docs/20/workflows/4157c9f8-9808-4f01-a152-5f6bdf3b68df/jobs/11
/home/circleci/project/napari/examples/add_vectors.py failed leaving traceback:
Traceback (most recent call last):
  File "/home/circleci/project/napari/examples/add_vectors.py", line 20, in <module>
    viewer = napari.Viewer()
  File "/home/circleci/project/napari/napari/viewer.py", line 67, in __init__
    self._window = Window(self, show=show)
  File "/home/circleci/project/napari/napari/_qt/qt_main_window.py", line 575, in __init__
    self._add_menus()
  File "/home/circleci/project/napari/napari/_qt/qt_main_window.py", line 731, in _add_menus
    self.view_menu = build_qmodel_menu(
  File "/home/circleci/project/napari/napari/_qt/_qapp_model/_menus.py", line 32, in build_qmodel_menu
    return QModelMenu(
  File "/home/circleci/project/venv/lib/python3.10/site-packages/app_model/backends/qt/_qmenu.py", line 145, in __init__
    _MenuMixin.__init__(self, menu_id, app)
  File "/home/circleci/project/venv/lib/python3.10/site-packages/app_model/backends/qt/_qmenu.py", line 56, in __init__
    self.rebuild()
  File "/home/circleci/project/venv/lib/python3.10/site-packages/app_model/backends/qt/_qmenu.py", line 81, in rebuild
    submenu = QModelSubmenu(item, self._app, parent=self)
  File "/home/circleci/project/venv/lib/python3.10/site-packages/app_model/backends/qt/_qmenu.py", line 189, in __init__
    super().__init__(
  File "/home/circleci/project/venv/lib/python3.10/site-packages/app_model/backends/qt/_qmenu.py", line 145, in __init__
    _MenuMixin.__init__(self, menu_id, app)
  File "/home/circleci/project/venv/lib/python3.10/site-packages/app_model/backends/qt/_qmenu.py", line 56, in __init__
    self.rebuild()
  File "/home/circleci/project/venv/lib/python3.10/site-packages/app_model/backends/qt/_qmenu.py", line 84, in rebuild
    action = QMenuItemAction(
  File "/home/circleci/project/venv/lib/python3.10/site-packages/app_model/backends/qt/_qaction.py", line 166, in __init__
    self.update_from_context({})
  File "/home/circleci/project/venv/lib/python3.10/site-packages/app_model/backends/qt/_qaction.py", line 170, in update_from_context
    super().update_from_context(ctx)
  File "/home/circleci/project/venv/lib/python3.10/site-packages/app_model/backends/qt/_qaction.py", line 94, in update_from_context
    self.setEnabled(expr.eval(ctx) if (expr := self._cmd_rule.enablement) else True)
RuntimeError: Internal C++ object (QMenuItemAction) already deleted.

Expected behavior
Build log should not contain any such bug.

Environment

Please copy and paste the information at napari info option in help menubar here:

Any other relevant information:

Additional context

BTW, all of these are related to examples - they probably need to be updated to account for changes in recent versions of napari.

This is being discussed/addressed here:
https://github.com/napari/docs/pull/178
Those errors appear related to pyside2, but there also appears to be a memory issue, probably due to clean up of viewers?

I close this issue as it is properly traced in the docs repo


Params issue

So I tried to add additional models, basing off of the articles model. Add controllers, ng controllers etc etc. I believe I have everything. The page displays, but when I try to create I'm getting a 404 and it's passing in http://localhost:3000/polls/:[poll]Id. Why is it adding :[poll]Id to the url? I feel like I'm missing something simple.