Skip to content

Conversation

leotaku
Copy link

@leotaku leotaku commented Sep 6, 2025

Context

When the PHP_CLI_SERVER_WORKERS environment variable is set to >=2, the PHP error log contains a flood of error messages titled "Failed to poll event". It seems like more service workers also increase the number and likelyhood of these messages.

This has previously been reported to the Laravel project, where they filter out this message from their logs manually: laravel/framework#52094

Output log
$ PHP_CLI_SERVER_WORKERS=10 php -S localhost:8080 index.php
[117756] [Sat Sep  6 13:48:43 2025] PHP 8.4.12 Development Server (http://localhost:8080) started
[117757] [Sat Sep  6 13:48:43 2025] PHP 8.4.12 Development Server (http://localhost:8080) started
[117758] [Sat Sep  6 13:48:43 2025] PHP 8.4.12 Development Server (http://localhost:8080) started
[117759] [Sat Sep  6 13:48:43 2025] PHP 8.4.12 Development Server (http://localhost:8080) started
[117760] [Sat Sep  6 13:48:43 2025] PHP 8.4.12 Development Server (http://localhost:8080) started
[117761] [Sat Sep  6 13:48:43 2025] PHP 8.4.12 Development Server (http://localhost:8080) started
[117762] [Sat Sep  6 13:48:43 2025] PHP 8.4.12 Development Server (http://localhost:8080) started
[117763] [Sat Sep  6 13:48:43 2025] PHP 8.4.12 Development Server (http://localhost:8080) started
[117755] [Sat Sep  6 13:48:43 2025] PHP 8.4.12 Development Server (http://localhost:8080) started
[117764] [Sat Sep  6 13:48:43 2025] PHP 8.4.12 Development Server (http://localhost:8080) started
[117765] [Sat Sep  6 13:48:43 2025] PHP 8.4.12 Development Server (http://localhost:8080) started
[117755] [Sat Sep  6 13:48:47 2025] [::1]:43226 Accepted
[117755] [Sat Sep  6 13:48:47 2025] [::1]:43226 Closing
[117755] [Sat Sep  6 13:48:50 2025] [::1]:38070 Accepted
[117757] [Sat Sep  6 13:48:50 2025] Failed to poll event
[117760] [Sat Sep  6 13:48:50 2025] Failed to poll event
[117755] [Sat Sep  6 13:48:50 2025] [::1]:38070 Closing
[117759] [Sat Sep  6 13:48:51 2025] [::1]:38084 Accepted
[117759] [Sat Sep  6 13:48:51 2025] [::1]:38084 Closing
[117759] [Sat Sep  6 13:48:52 2025] Failed to poll event
[117760] [Sat Sep  6 13:48:52 2025] Failed to poll event
[117757] [Sat Sep  6 13:48:52 2025] Failed to poll event
[117755] [Sat Sep  6 13:48:52 2025] [::1]:38092 Accepted
[117755] [Sat Sep  6 13:48:52 2025] [::1]:38092 Closing
[117757] [Sat Sep  6 13:48:53 2025] Failed to poll event
[117759] [Sat Sep  6 13:48:53 2025] Failed to poll event
[117763] [Sat Sep  6 13:48:53 2025] [::1]:38102 Accepted
[117763] [Sat Sep  6 13:48:53 2025] [::1]:38102 Closing
[117763] [Sat Sep  6 13:48:55 2025] Failed to poll event
[117759] [Sat Sep  6 13:48:55 2025] [::1]:38116 Accepted
[117757] [Sat Sep  6 13:48:55 2025] Failed to poll event
[117759] [Sat Sep  6 13:48:55 2025] [::1]:38116 Closing
[117759] [Sat Sep  6 13:48:56 2025] Failed to poll event
[117755] [Sat Sep  6 13:48:56 2025] Failed to poll event
[117763] [Sat Sep  6 13:48:56 2025] Failed to poll event
[117757] [Sat Sep  6 13:48:56 2025] [::1]:38118 Accepted
[117757] [Sat Sep  6 13:48:56 2025] [::1]:38118 Closing

My diagnosis

I think this happens because multiple workers will (correctly) poll on the same set of shared file descriptors. As the workers get notified that a file descriptor is ready, they race to accept. However, only the first worker will succeed, while others receive an EAGAIN error.

My solution

My solution simply considers a socket callback getting an EAGAIN error as that callback succeeding. I think this is fine, because I assume that the only way the accept call would return this error code is because the request is already being handled by another worker. It is possible that this assumption is incorrect, in which case a different solution would be required.

It would also be possible to simply remove or downgrade the "Failed to poll event" as real connection errors already get logged here.

@krakjoe
Copy link
Member

krakjoe commented Sep 18, 2025

This looks reasonable enough to me.

I'm uncertain it's the only error code that should re-enter accept(), possibly ECONNABORTED might also be necessary for the case where the client went away before accept could finish.

@leotaku
Copy link
Author

leotaku commented Sep 21, 2025

Thanks for the feedback! I'm not totally sure under what conditions errno == ECONNABORTED, but from some light research, it seems like the user should still be shown an error message when it happens.

@krakjoe
Copy link
Member

krakjoe commented Sep 21, 2025

So implementations may vary, I only looked at linux x86. During connect, the socket operations may attempt to retrieve the peer name (addr), if between the call to ops->accept and ops->getpeer the client closed the connection, ECONNABORTED will be returned by accept(). When it is, it looks reasonable to deal with it the same as EAGAIN - there's nothing else really to do, there's no client to communicate with and no sense in executing further ... it looks as if this may be raised in the same sort of networking environments as EAGAIN, but this is just a guess, I've never seen it.

I don't object to just dealing with EAGAIN, so long as we've considered the possibility of dealing with everything relevant ... which we have ...

Copy link
Member

@bukka bukka left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I just did a bit of checking and it happens because exactly what OP described - the EAGAIN is returned when another worker accepted the request. This is because server_sock is non blocking. So this is an expected behavior and it's quite usual for non blocking socket to happen. It's basically sort of race condition between select and accept. It should be treated as SUCCESS.

On the other side ECONNABORTED is an issue that should be notified because client dropped the connection unexpectadly so it might be worth to log. This should not normally happen so I don't think there should be an extra handling.

This ensures that no useless "Failed to poll event" error messages are
logged during normal server operation, as the SOCK_EAGAIN error simply
indicates another worker is already serving the request.
@leotaku leotaku force-pushed the polling-error-php8.3 branch from 22b141a to 46588d9 Compare October 1, 2025 18:04
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants