UNRAID - Starting PHP-FPM stuck in loop when restarting

[BenPicard]

Summary

If I stop the docker and restart the docker, it won't start. It will be stuck in an infinite loop with Starting php-fpm. I use the docker in Unraid. If I force the docker to update, it will finally start.

I tried with the latest, latest 7.4 and latest 7.3. I have this bug everywhere.

Steps to reproduce

Stop the docker, wait for it to be stop and then, restart it.

What is the expected correct behavior?

It should start.

Relevant logs and/or screenshots

[s6-init] making user provided files available at /var/run/s6/etc...exited 0. [s6-init] ensuring user provided files have correct perms...exited 0. [fix-attrs.d] applying ownership & permissions fixes... [fix-attrs.d] 00-functions: applying... [fix-attrs.d] 00-functions: exited 0. [fix-attrs.d] 01-s6: applying... [fix-attrs.d] 01-s6: exited 0. [fix-attrs.d] 02-zabbix: applying... [fix-attrs.d] 02-zabbix: exited 0. [fix-attrs.d] 03-logrotate: applying... [fix-attrs.d] 03-logrotate: exited 0. [fix-attrs.d] done. [cont-init.d] executing container initialization scripts... [cont-init.d] 00-startup: executing... 2021-11-10-10:03:36 [NOTICE] [container-init] Detected Container that has been restarted - Cleaning '/tmp/state' files [cont-init.d] 00-startup: exited 0. [cont-init.d] 01-timezone: executing... [cont-init.d] 01-timezone: exited 0. [cont-init.d] 02-permissions: executing... [cont-init.d] 02-permissions: exited 0. [cont-init.d] 03-monitoring: executing... 2021-11-10-10:03:36 [NOTICE] [monitoring] Container configured for monitoring with 'zabbix modern' [cont-init.d] 03-monitoring: exited 0. [cont-init.d] 04-scheduling: executing... 2021-11-10-10:03:36 [NOTICE] [scheduling] Container configured for scheduled tasks with 'cron' [cont-init.d] 04-scheduling: exited 0. [cont-init.d] 05-logging: executing... 2021-11-10-10:03:36 [NOTICE] [logging] Disabling Log Shipping Functionality [cont-init.d] 05-logging: exited 0. [cont-init.d] 06-messaging: executing... 2021-11-10-10:03:36 [NOTICE] [messaging] Container configured to route mail via SMTP to 'postfix-relay' [cont-init.d] 06-messaging: exited 0. [cont-init.d] 10-nginx: executing... 2021-11-10-10:03:36 [NOTICE] [nginx] Disable Nginx FastCGI HTTPS Termination Support [cont-init.d] 10-nginx: exited 0. [cont-init.d] 11-nginx-config-reload: executing... [cont-init.d] 11-nginx-config-reload: exited 0. [cont-init.d] 20-php-fpm: executing... 2021-11-10-10:03:37 [NOTICE] [php-fpm] PHP-FPM Preparing to start with the following plugins enabled: apcu bcmath bz2 ctype curl dom exif fileinfo gd gnupg iconv imap intl ldap mbstring mysqli mysqlnd opcache openssl pdo pdo_mysql pgsql phar session simplexml tokenizer xml xmlreader xmlwriter zip [cont-init.d] 20-php-fpm: exited 0. [cont-init.d] 30-freescout: executing... 2021-11-10-10:03:37 [INFO] [freescout] Auto Configuring based on Environment Variables 2021-11-10-10:03:38 [WARN] [freescout] Installing Modules into container 2021-11-10-10:03:38 [WARN] [freescout] Running any Database Migrations 2021-11-10-10:03:39 [INFO] [freescout] Initialization Complete. Please visit https://xxxxxxxxxxxxx and login with your credentials.. [cont-init.d] 30-freescout: exited 0. [cont-init.d] 99-container: executing... [cont-init.d] 99-container: exited 0. [cont-init.d] done. [services.d] starting services [services.d] done. 2021-11-10-10:03:39 [STARTING] [nginx] [1] Starting nginx 1.21.3 2021-11-10-10:03:39 [STARTING] [monitoring] [1] Starting Zabbix Agent (modern) 5.4.5 2021-11-10-10:03:39 [STARTING] [php-fpm] [1] Starting php-fpm 8.0.12 2021-11-10-10:03:39 [STARTING] [scheduling] [1] Starting cron 2021-11-10-10:03:40 [STARTING] [php-fpm] [2] Starting php-fpm 8.0.12 2021-11-10-10:03:40 [STARTING] [php-fpm] [2] Starting php-fpm 8.0.12 2021-11-10-10:03:41 [STARTING] [php-fpm] [3] Starting php-fpm 8.0.12 2021-11-10-10:03:42 [STARTING] [php-fpm] [4] Starting php-fpm 8.0.12 2021-11-10-10:03:43 [STARTING] [php-fpm] [5] Starting php-fpm 8.0.12 2021-11-10-10:03:44 [STARTING] [php-fpm] [6] Starting php-fpm 8.0.12 2021-11-10-10:03:45 [STARTING] [php-fpm] [7] Starting php-fpm 8.0.12 2021-11-10-10:03:46 [STARTING] [php-fpm] [8] Starting php-fpm 8.0.12 2021-11-10-10:03:47 [STARTING] [php-fpm] [9] Starting php-fpm 8.0.12 2021-11-10-10:03:48 [STARTING] [php-fpm] [10] Starting php-fpm 8.0.12 2021-11-10-10:03:49 [STARTING] [php-fpm] [11] Starting php-fpm 8.0.12 2021-11-10-10:03:50 [STARTING] [php-fpm] [12] Starting php-fpm 8.0.12 2021-11-10-10:03:51 [STARTING] [php-fpm] [13] Starting php-fpm 8.0.12 2021-11-10-10:03:52 [STARTING] [php-fpm] [14] Starting php-fpm 8.0.12 2021-11-10-10:03:53 [STARTING] [php-fpm] [15] Starting php-fpm 8.0.12 2021-11-10-10:03:54 [STARTING] [php-fpm] [16] Starting php-fpm 8.0.12 2021-11-10-10:03:55 [STARTING] [php-fpm] [17] Starting php-fpm 8.0.12 2021-11-10-10:03:56 [STARTING] [php-fpm] [18] Starting php-fpm 8.0.12 2021-11-10-10:03:57 [STARTING] [php-fpm] [19] Starting php-fpm 8.0.12 2021-11-10-10:03:58 [STARTING] [php-fpm] [20] Starting php-fpm 8.0.12 2021-11-10-10:03:59 [STARTING] [php-fpm] [21] Starting php-fpm 8.0.12 2021-11-10-10:04:00 [STARTING] [php-fpm] [22] Starting php-fpm 8.0.12 2021-11-10-10:04:01 [STARTING] [php-fpm] [23] Starting php-fpm 8.0.12 2021-11-10-10:04:01 [STARTING] [php-fpm] [23] Starting php-fpm 8.0.12 2021-11-10-10:04:02 [STARTING] [php-fpm] [24] Starting php-fpm 8.0.12 2021-11-10-10:04:03 [STARTING] [php-fpm] [25] Starting php-fpm 8.0.12 2021-11-10-10:04:03 [STARTING] [php-fpm] [25] Starting php-fpm 8.0.12 2021-11-10-10:04:04 [STARTING] [php-fpm] [26] Starting php-fpm 8.0.12 2021-11-10-10:04:05 [STARTING] [php-fpm] [27] Starting php-fpm 8.0.12 2021-11-10-10:04:05 [STARTING] [php-fpm] [27] Starting php-fpm 8.0.12 2021-11-10-10:04:06 [STARTING] [php-fpm] [28] Starting php-fpm 8.0.12 2021-11-10-10:04:07 [STARTING] [php-fpm] [29] Starting php-fpm 8.0.12 2021-11-10-10:04:07 [STARTING] [php-fpm] [29] Starting php-fpm 8.0.12 2021-11-10-10:04:08 [STARTING] [php-fpm] [30] Starting php-fpm 8.0.12 2021-11-10-10:04:09 [STARTING] [php-fpm] [31] Starting php-fpm 8.0.12 2021-11-10-10:04:09 [STARTING] [php-fpm] [31] Starting php-fpm 8.0.12 2021-11-10-10:04:10 [STARTING] [php-fpm] [32] Starting php-fpm 8.0.12 2021-11-10-10:04:11 [STARTING] [php-fpm] [33] Starting php-fpm 8.0.12 2021-11-10-10:04:11 [STARTING] [php-fpm] [33] Starting php-fpm 8.0.12 2021-11-10-10:04:12 [STARTING] [php-fpm] [34] Starting php-fpm 8.0.12 2021-11-10-10:04:13 [STARTING] [php-fpm] [35] Starting php-fpm 8.0.12

Environment

• Image version / tag: latest, latest7.4, latest7.3
• Host OS: Unraid OS

[tiredofit]

It looks as if your system only starts and stops a container, as opposed to killing it completely before restart. Can you try to find a way to stop (and remove) it from the container list, so that the container can have a "hard" start? This is one of the gotchas of some of these multi process images I build.

[BenPicard]

It looks as if your system only starts and stops a container, as opposed to killing it completely before restart. Can you try to find a way to stop (and remove) it from the container list, so that the container can have a "hard" start? This is one of the gotchas of some of these multi process images I build.

Thank you for the quick reply. There are not a lot of option possible from the Unraid UI. Maybe this is something related to the way unraid and dockers works? I have been running dockers in Unraid since 3-4 years and this is the first time that I got this error.

[tiredofit]

It's been a long time since we have seen this type of error to be honest. I don't know much about Unraid, but it seems then if you are clicking stop is doesn't fully remove the container from the "active" container list.

If you had access to a console of unraid, you would be able to see this with by typing docker container ls and seeing that your container was still available, yet stopped.

I really only have experience with docker command line and docker-compose, When I type docker-compose down it stops and destroys the container.

You may need to fiddle around with some settings or try different scenarios - this it eh log file that jumps out at me:

[cont-init.d] 00-startup: executing...
2021-11-10-10:03:36 �[100m[NOTICE]�[49m ** [container-init] Detected Container that has been restarted - Cleaning '/tmp/state' files

That shouldn't theoretically appear if it is a "fresh" or "hard" start. I'm certain there are other unraid users using this image as its quite popular, lets see if someone can help us? I will change the topic.

[tiredofit]

One thing you can do as well would be to go inside the container as it seems this is more a PHP issue than a freescout issue and manually type php-fpm and see what the output is?

[BenPicard]

One thing you can do as well would be to go inside the container as it seems this is more a PHP issue than a freescout issue and manually type php-fpm and see what the output is?

/ # php-fpm [10-Nov-2021 14:56:31] ALERT: [pool www] user has not been defined [10-Nov-2021 14:56:31] ERROR: failed to post process the configuration [10-Nov-2021 14:56:31] ERROR: FPM initialization failed

[BenPicard]

It's been a long time since we have seen this type of error to be honest. I don't know much about Unraid, but it seems then if you are clicking stop is doesn't fully remove the container from the "active" container list.

If you had access to a console of unraid, you would be able to see this with by typing docker container ls and seeing that your container was still available, yet stopped.

I really only have experience with docker command line and docker-compose, When I type docker-compose down it stops and destroys the container.

You may need to fiddle around with some settings or try different scenarios - this it eh log file that jumps out at me:

[cont-init.d] 00-startup: executing...
2021-11-10-10:03:36 �[100m[NOTICE]�[49m ** [container-init] Detected Container that has been restarted - Cleaning '/tmp/state' files

That shouldn't theoretically appear if it is a "fresh" or "hard" start. I'm certain there are other unraid users using this image as its quite popular, lets see if someone can help us? I will change the topic.

Not sure if it's a useful information.

[tiredofit]

Something is coming up here which sounds like exactly what you are experiencing: https://github.com/tiredofit/docker-fusiondirectory/issues/47

Can you output the contents of your /etc/php*/php-fpm.conf file for me?

[BenPicard]

Something is coming up here which sounds like exactly what you are experiencing: tiredofit/docker-fusiondirectory#47

Can you output the contents of your /etc/php*/php-fpm.conf file for me?

`rror_log = /www/logs/php-fpm/error.log log_level = notice log_limit = 2048

[www] listen = 0.0.0.0:9000 listen.owner = nginx listen.group = www-data

access.log = /www/logs/php-fpm/access.log

pm = dynamic pm.max_children = 75 pm.start_servers = 2 pm.min_spare_servers = 1 pm.max_spare_servers = 3 pm.status_path = /php-fpm_status ping.path = /ping

pm.process_idle_timeout = 10s pm.max_requests = 500 php_admin_value[max_execution_time] = 180 php_admin_value[max_input_nesting_level] = 256 php_admin_value[max_input_vars] = 10000 php_admin_value[memory_limit] = 128M php_admin_value[openssl.cafile] = /etc/ssl/certs/ca-certificates.crt php_admin_value[openssl.capath] = /etc/ssl/certs php_admin_value[output_buffering] = 0 php_admin_value[post_max_size] = 2G php_admin_value[upload_max_filesize] = 2G php_flag[display_errors] = on catch_workers_output = yes

env[PATH] = /usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin env[TMP] = /tmp env[TMPDIR] = /tmp env[TEMP] = /tmp access.format='%{%Y-%m-%dT%H:%M:%S%z}T %{HTTP_X_FORWARDED_FOR}e %R %u %s %m "%{REQUEST_URI}e" %{HTTP_X_REQUEST_ID}e %{SERVER_PROTOCOL}e %l "%{HTTP_REFERE ~ ~ ~ ~ ~`

[BenPicard]

@tiredofit did you change something in the last update? it seems to be fixed now !!

[tiredofit]

:) I did! It just so happens that the other issue that popped up in fusiondirectory brought a change to light that was made about 1.5 months ago only surfacing now. Definitely related to containers not fully stopping and being destroyed,so I bought a few safety nets in place to avoid a duplication of configuration settings which was causing the failure. Glad it is working for you now and thanks for your patience and your submissions.

[BenPicard]

:) I did! It just so happens that the other issue that popped up in fusiondirectory brought a change to light that was made about 1.5 months ago only surfacing now. Definitely related to containers not fully stopping and being destroyed,so I bought a few safety nets in place to avoid a duplication of configuration settings which was causing the failure. Glad it is working for you now and thanks for your patience and your submissions.

Thank you so much for the quick support