Symfony application error : readv() failed (104: Connection reset by peer) while reading upstream

[eotin]

I'm developing a Symfony application from base image webdevops/php-nginx-dev:8.3 and everything was going well until the end of last week when i've rebuild my containers.

Now we have our app not responding to any request, because of the following issue :

readv() failed (104: Connection reset by peer) while reading upstream, client: 172.24.0.1, server: _, request: "GET /webifa/afg/api/v4/app-config HTTP/1.1", upstream: "fastcgi://127.0.0.1:9000", host: "localhost:8081"

Our local configuration of our env dev did not change recently and i didn't understand why this issue is coming now.

These is our nginx config file the replace the one in the container :

location ~ "^\/webifa\/([a-z]{3})"
{
    set $COUNTRY $1;
    try_files $uri /index.php?$query_string;
}

location ~ \.php$
{
    fastcgi_split_path_info ^(.+\.php)(/.+)$;
    fastcgi_pass php;
    include fastcgi_params;
    fastcgi_param SCRIPT_FILENAME     $request_filename;
    fastcgi_param COUNTRY     $COUNTRY;
    fastcgi_read_timeout 600;
    fastcgi_buffer_size 32k;
    fastcgi_buffers 8 16k;
}

Here is my custom DockerFile :

FROM webdevops/php-nginx-dev:8.3 as base-image

WORKDIR /app

# nc is used in bin/docker-entrypoint.d/30-wait-for-database.sh
RUN apt-get update
RUN apt-get install netcat-traditional -y

RUN curl -sS https://get.symfony.com/cli/installer | bash
RUN mv /root/.symfony5/bin/symfony /usr/local/bin/symfony


FROM webdevops/php-nginx:8.3 as prod

WORKDIR /app

# nc is used in bin/docker-entrypoint.d/30-wait-for-database.sh
RUN apt-get update
RUN apt-get install netcat-traditional -y

RUN curl -sS https://get.symfony.com/cli/installer | bash
RUN mv /root/.symfony5/bin/symfony /usr/local/bin/symfony

COPY docker/webserver/nginx/10-php.conf /opt/docker/etc/nginx/vhost.common.d/10-php.conf

# See https://dockerfile.readthedocs.io/en/latest/content/DockerImages/dockerfiles/base.html#provisioning
COPY bin/docker-entrypoint.d/*  /opt/docker/provision/entrypoint.d/

COPY . .

ENV COMPOSER_ALLOW_SUPERUSER=1
RUN composer install

Thanks for your inputs

[htuscher]

Sorry, I can't reproduce that. The FPM config seems not to be causing this issue.

Are there any other logs. Usually that error is caused by a SIGSEGV of PHP.

[eotin]

Sorry, I can't reproduce that. The FPM config seems not to be causing this issue.

Are there any other logs. Usually that error is caused by a SIGSEGV of PHP.

Thanks for your reply.

We tested the same application with an old image we still have in our cache with this configuration and it works perfectly :

nginx version: nginx/1.24.0
built by gcc 12.2.0 (Debian 12.2.0-14)
built with OpenSSL 3.0.9 30 May 2023 (running with OpenSSL 3.0.11 19 Sep 2023)
TLS SNI support enabled
configure arguments: --prefix=/etc/nginx --sbin-path=/usr/sbin/nginx --modules-path=/usr/lib/nginx/modules --conf-path=/etc/nginx/nginx.conf --error-log-path=/var/log/nginx/error.log --http-log-path=/var/log/nginx/access.log --pid-path=/var/run/nginx.pid --lock-path=/var/run/nginx.lock --http-client-body-temp-path=/var/cache/nginx/client_temp --http-proxy-temp-path=/var/cache/nginx/proxy_temp --http-fastcgi-temp-path=/var/cache/nginx/fastcgi_temp --http-uwsgi-temp-path=/var/cache/nginx/uwsgi_temp --http-scgi-temp-path=/var/cache/nginx/scgi_temp --user=nginx --group=nginx --with-compat --with-file-aio --with-threads --with-http_addition_module --with-http_auth_request_module --with-http_dav_module --with-http_flv_module --with-http_gunzip_module --with-http_gzip_static_module --with-http_mp4_module --with-http_random_index_module --with-http_realip_module --with-http_secure_link_module --with-http_slice_module --with-http_ssl_module --with-http_stub_status_module --with-http_sub_module --with-http_v2_module --with-mail --with-mail_ssl_module --with-stream --with-stream_realip_module --with-stream_ssl_module --with-stream_ssl_preread_module --with-cc-opt='-g -O2 -ffile-prefix-map=/data/builder/debuild/nginx-1.24.0/debian/debuild-base/nginx-1.24.0=. -fstack-protector-strong -Wformat -Werror=format-security -Wp,-D_FORTIFY_SOURCE=2 -fPIC' --with-ld-opt='-Wl,-z,relro -Wl,-z,now -Wl,--as-needed -pie'

The new image and new configuration raises the issue :

nginx version: nginx/1.26.1
built by gcc 12.2.0 (Debian 12.2.0-14)
built with OpenSSL 3.0.11 19 Sep 2023 (running with OpenSSL 3.0.13 30 Jan 2024)
TLS SNI support enabled
configure arguments: --prefix=/etc/nginx --sbin-path=/usr/sbin/nginx --modules-path=/usr/lib/nginx/modules --conf-path=/etc/nginx/nginx.conf --error-log-path=/var/log/nginx/error.log --http-log-path=/var/log/nginx/access.log --pid-path=/var/run/nginx.pid --lock-path=/var/run/nginx.lock --http-client-body-temp-path=/var/cache/nginx/client_temp --http-proxy-temp-path=/var/cache/nginx/proxy_temp --http-fastcgi-temp-path=/var/cache/nginx/fastcgi_temp --http-uwsgi-temp-path=/var/cache/nginx/uwsgi_temp --http-scgi-temp-path=/var/cache/nginx/scgi_temp --user=nginx --group=nginx --with-compat --with-file-aio --with-threads --with-http_addition_module --with-http_auth_request_module --with-http_dav_module --with-http_flv_module --with-http_gunzip_module --with-http_gzip_static_module --with-http_mp4_module --with-http_random_index_module --with-http_realip_module --with-http_secure_link_module --with-http_slice_module --with-http_ssl_module --with-http_stub_status_module --with-http_sub_module --with-http_v2_module --with-http_v3_module --with-mail --with-mail_ssl_module --with-stream --with-stream_realip_module --with-stream_ssl_module --with-stream_ssl_preread_module --with-cc-opt='-g -O2 -ffile-prefix-map=/data/builder/debuild/nginx-1.26.1/debian/debuild-base/nginx-1.26.1=. -fstack-protector-strong -Wformat -Werror=format-security -Wp,-D_FORTIFY_SOURCE=2 -fPIC' --with-ld-opt='-Wl,-z,relro -Wl,-z,now -Wl,--as-needed -pie'

[htuscher]

I'm quite sure the nginx version has nothing to do with it. The FastCGI request lost the connection that happens if PHP-FPM breaks. Which is most of the times a SIGSEGV.

Please check the other lines of the log before and after readv() failed. There should be a log from PHP-FPM telling what actually is the issue. The nginx log just tells you it lost connection to PHP-FPM, not what caused it.

[eotin]

I'm quite sure the nginx version has nothing to do with it. The FastCGI request lost the connection that happens if PHP-FPM breaks. Which is most of the times a SIGSEGV.

Please check the other lines of the log before and after readv() failed. There should be a log from PHP-FPM telling what actually is the issue. The nginx log just tells you it lost connection to PHP-FPM, not what caused it.

We do have a SIGSEGV but no more logs of the cause of this SIGSEGV. (We do not have one with the version webdevops/php-nginx:8.3@sha256:3c215733f28569cbd2da1449788c7bc097112e534ef926425722b593fa0880f9)

2024-07-09 17:58:40 [09-Jul-2024 15:58:40.538074] DEBUG: pid 260, fpm_stdio_save_original_stderr(), line 81: saving original STDERR fd: dup()
2024-07-09 17:58:40 [09-Jul-2024 15:58:40.538125] DEBUG: pid 260, fpm_log_open(), line 51: open access log (/proc/self/fd/2)
2024-07-09 17:58:40 [09-Jul-2024 15:58:40.538183] DEBUG: pid 260, fpm_scoreboard_init_main(), line 38: got clock tick '100'
2024-07-09 17:58:40 [09-Jul-2024 15:58:40.538205] DEBUG: pid 260, fpm_signals_init_main(), line 219: Unblocking all signals
2024-07-09 17:58:40 [09-Jul-2024 15:58:40.538225] DEBUG: pid 260, fpm_socket_af_inet_socket_by_addr(), line 324: Found address for ::, socket opened on ::
2024-07-09 17:58:40 [09-Jul-2024 15:58:40.538232] DEBUG: pid 260, fpm_event_init_main(), line 354: event module is epoll and 11 fds have been reserved
2024-07-09 17:58:40 [09-Jul-2024 15:58:40.538287] NOTICE: pid 260, fpm_init(), line 83: fpm is running, pid 260
2024-07-09 17:58:40 [09-Jul-2024 15:58:40.538325] DEBUG: pid 260, fpm_children_make(), line 449: blocking signals before child birth
2024-07-09 17:58:40 [09-Jul-2024 15:58:40.539287] DEBUG: pid 260, fpm_children_make(), line 473: unblocking signals, child born
2024-07-09 17:58:40 [09-Jul-2024 15:58:40.539334] DEBUG: pid 260, fpm_children_make(), line 479: [pool www] child 266 started
2024-07-09 17:58:40 [09-Jul-2024 15:58:40.539357] DEBUG: pid 260, fpm_children_make(), line 449: blocking signals before child birth
2024-07-09 17:58:40 [09-Jul-2024 15:58:40.540314] DEBUG: pid 260, fpm_children_make(), line 473: unblocking signals, child born
2024-07-09 17:58:40 [09-Jul-2024 15:58:40.540347] DEBUG: pid 260, fpm_children_make(), line 479: [pool www] child 267 started
2024-07-09 17:58:40 [09-Jul-2024 15:58:40.540369] DEBUG: pid 260, fpm_event_loop(), line 382: 5968 bytes have been reserved in SHM
2024-07-09 17:58:40 [09-Jul-2024 15:58:40.540370] NOTICE: pid 260, fpm_event_loop(), line 383: ready to handle connections
2024-07-09 17:58:41 [09-Jul-2024 15:58:41.540831] DEBUG: pid 260, fpm_pctl_perform_idle_server_maintenance(), line 398: [pool www] currently 0 active children, 2 spare children, 2 running children. Spawning rate 1
2024-07-09 17:58:42 [09-Jul-2024 15:58:42.541919] DEBUG: pid 260, fpm_pctl_perform_idle_server_maintenance(), line 398: [pool www] currently 0 active children, 2 spare children, 2 running children. Spawning rate 1
2024-07-09 17:58:43 [09-Jul-2024 15:58:43.543028] DEBUG: pid 260, fpm_pctl_perform_idle_server_maintenance(), line 398: [pool www] currently 0 active children, 2 spare children, 2 running children. Spawning rate 1
2024-07-09 17:58:44 [09-Jul-2024 15:58:44.544191] DEBUG: pid 260, fpm_pctl_perform_idle_server_maintenance(), line 398: [pool www] currently 0 active children, 2 spare children, 2 running children. Spawning rate 1
2024-07-09 17:58:45 [09-Jul-2024 15:58:45.545277] DEBUG: pid 260, fpm_pctl_perform_idle_server_maintenance(), line 398: [pool www] currently 0 active children, 2 spare children, 2 running children. Spawning rate 1
2024-07-09 17:58:46 [09-Jul-2024 15:58:46.546141] DEBUG: pid 260, fpm_pctl_perform_idle_server_maintenance(), line 398: [pool www] currently 0 active children, 2 spare children, 2 running children. Spawning rate 1
2024-07-09 17:58:47 [09-Jul-2024 15:58:47.547067] DEBUG: pid 260, fpm_pctl_perform_idle_server_maintenance(), line 398: [pool www] currently 0 active children, 2 spare children, 2 running children. Spawning rate 1
2024-07-09 17:58:48 [09-Jul-2024 15:58:48.548254] DEBUG: pid 260, fpm_pctl_perform_idle_server_maintenance(), line 398: [pool www] currently 0 active children, 2 spare children, 2 running children. Spawning rate 1
2024-07-09 17:58:49 [09-Jul-2024 15:58:49.549469] DEBUG: pid 260, fpm_pctl_perform_idle_server_maintenance(), line 398: [pool www] currently 0 active children, 2 spare children, 2 running children. Spawning rate 1
2024-07-09 17:58:50 172.24.0.1 - - [09/Jul/2024:15:58:50 +0000] "GET /webifa/afg/api/v4/app-config HTTP/1.1" 502 157 "-" "axios/1.5.1"
2024-07-09 17:58:50 2024/07/09 15:58:50 [error] 96#96: *1 recv() failed (104: Connection reset by peer) while reading response header from upstream, client: 172.24.0.1, server: _, request: "GET /webifa/afg/api/v4/app-config HTTP/1.1", upstream: "fastcgi://127.0.0.1:9000", host: "localhost:8081"
2024-07-09 17:58:50 [09-Jul-2024 15:58:50.313508] DEBUG: pid 260, fpm_event_loop(), line 435: event module triggered 2 events
2024-07-09 17:58:50 [09-Jul-2024 15:58:50.313559] DEBUG: pid 260, fpm_got_signal(), line 82: received SIGCHLD
2024-07-09 17:58:50 [09-Jul-2024 15:58:50.313561] DEBUG: pid 260, fpm_event_loop(), line 435: event module triggered 1 events
2024-07-09 17:58:50 [09-Jul-2024 15:58:50.313588] WARNING: pid 260, fpm_children_bury(), line 300: [pool www] child 266 exited on signal 11 (SIGSEGV) after 9.774273 seconds from start
2024-07-09 17:58:50 [09-Jul-2024 15:58:50.313600] DEBUG: pid 260, fpm_children_make(), line 449: blocking signals before child birth
2024-07-09 17:58:50 [09-Jul-2024 15:58:50.315406] DEBUG: pid 260, fpm_children_make(), line 473: unblocking signals, child born
2024-07-09 17:58:50 [09-Jul-2024 15:58:50.315446] NOTICE: pid 260, fpm_children_make(), line 479: [pool www] child 274 started
2024-07-09 17:58:50 [09-Jul-2024 15:58:50.550727] DEBUG: pid 260, fpm_pctl_perform_idle_server_maintenance(), line 398: [pool www] currently 0 active children, 2 spare children, 2 running children. Spawning rate 1
2024-07-09 17:58:51 [09-Jul-2024 15:58:51.551682] DEBUG: pid 260, fpm_pctl_perform_idle_server_maintenance(), line 398: [pool www] currently 0 active children, 2 spare children, 2 running children. Spawning rate 1

By the Way, is it possible to give me a valid sha256 from 2 weeks ago for image webdevops/php-nginx-dev:8.3 i can use temporarily locally ?

Thanks

[TiFosi]

Hello, i have the same issue with webdevops/php-nginx-dev:8.3 but not with webdevops/php-nginx:8.3

11:36:09 [error] 115#115: *3 readv() failed (104: Connection reset by peer) while reading upstream

EDIT:
I did find an older sha256 that works for me
webdevops/php-nginx-dev:8.3@sha256:cfb12bff499ee205343e06d80d43c60ae3241e8b2a7986d3b399aa596f91dae2

[ndoulgeridis]

I can also verify it, for me it's happening only under Sonata admin controllers, not in some very basic simple Controllers I have for the front-end.

And I can also verify that with webdevops/php-nginx-dev:8.3@sha256:cfb12bff499ee205343e06d80d43c60ae3241e8b2a7986d3b399aa596f91dae2 it is working fine.

[maliiiith]

Not sure if these are related, but disabling ioncube resolved the issue for me: #523