Cloudron makes it easy to run web apps like WordPress, Nextcloud, GitLab on your server. Find out more or install now.


EspoCRM doesn't come online after server reboot



  • Just rebooted a server with three EspoCRM instances and one of those just wouldn't come online. The other two were fine, just the third one was stuck somehow. Restarting the app didn't work, starting and stopping didn't work, only entering recovery mode and exiting did the trick. This is the startup error (weird part: it said it was "Running" after restart, even though it was showing the Cloudron error page):

    ...
    Jul 18 12:07:51 => Running cron job
    Jul 18 12:07:51 => Starting EspoCRM
    Jul 18 12:07:52 2020-07-18 10:07:52,077 CRIT Supervisor running as root (no user in config file)
    Jul 18 12:07:52 2020-07-18 10:07:52,078 INFO Included extra file "/etc/supervisor/conf.d/web.conf" during parsing
    Jul 18 12:07:52 2020-07-18 10:07:52,078 INFO Included extra file "/etc/supervisor/conf.d/ws.conf" during parsing
    Jul 18 12:07:52 2020-07-18 10:07:52,088 INFO RPC interface 'supervisor' initialized
    Jul 18 12:07:52 2020-07-18 10:07:52,088 CRIT Server 'unix_http_server' running without any HTTP authentication checking
    Jul 18 12:07:52 2020-07-18 10:07:52,088 INFO supervisord started with pid 1
    Jul 18 12:07:53 2020-07-18 10:07:53,093 INFO spawned: 'web' with pid 34
    Jul 18 12:07:53 2020-07-18 10:07:53,102 INFO spawned: 'ws' with pid 35
    Jul 18 12:07:53 AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.18.0.12. Set the 'ServerName' directive globally to suppress this message
    Jul 18 12:07:53 httpd (pid 35) already running
    Jul 18 12:07:53 2020-07-18 10:07:53,189 INFO exited: web (exit status 0; not expected)
    Jul 18 12:07:54 2020-07-18 10:07:54,193 INFO spawned: 'web' with pid 39
    Jul 18 12:07:54 2020-07-18 10:07:54,194 INFO success: ws entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
    Jul 18 12:07:54 AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.18.0.12. Set the 'ServerName' directive globally to suppress this message
    Jul 18 12:07:54 httpd (pid 35) already running
    Jul 18 12:07:54 2020-07-18 10:07:54,247 INFO exited: web (exit status 0; not expected)
    Jul 18 12:07:56 2020-07-18 10:07:56,254 INFO spawned: 'web' with pid 41
    Jul 18 12:07:56 AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.18.0.12. Set the 'ServerName' directive globally to suppress this message
    Jul 18 12:07:56 httpd (pid 35) already running
    Jul 18 12:07:56 2020-07-18 10:07:56,310 INFO exited: web (exit status 0; not expected)
    Jul 18 12:07:59 2020-07-18 10:07:59,319 INFO spawned: 'web' with pid 43
    Jul 18 12:07:59 AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.18.0.12. Set the 'ServerName' directive globally to suppress this message
    Jul 18 12:07:59 httpd (pid 35) already running
    Jul 18 12:07:59 2020-07-18 10:07:59,380 INFO exited: web (exit status 0; not expected)
    Jul 18 12:08:00 2020-07-18 10:08:00,382 INFO gave up: web entered FATAL state, too many start retries too quickly
    

  • Staff

    This looks like a bug in the apache handling through supervisor. I will see how this can be fixed.


  • Staff

    This should be fixed with latest version



  • thanks @nebulon, will keep you posted!



  • Hi,
    got the same situation. In the morning when we get to work sometime ESPO show time out.
    When i restart the app it does not work after restart and i got the same Log:

    Sep 11 08:54:28 172.18.0.1 - - [11/Sep/2020:06:21:26 +0000] "GET /wss?authToken=25d42c15ebe92b32848bcacdd4afea99&userId=5d7f329de51b1ed1b HTTP/1.1" 200 411 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36"
    Sep 11 08:54:28 172.18.0.1 - - [11/Sep/2020:06:25:34 +0000] "GET /wss?authToken=ddaa4f9384347a9dd9cf43adafbedee2&userId=5d81fc47394db142f HTTP/1.1" 200 555 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:80.0) Gecko/20100101 Firefox/80.0"
    Sep 11 08:54:28 172.18.0.1 - - [11/Sep/2020:06:49:20 +0000] "GET /wss?authToken=ddaa4f9384347a9dd9cf43adafbedee2&userId=5d81fc47394db142f HTTP/1.1" 200 247 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:80.0) Gecko/20100101 Firefox/80.0"
    Sep 11 08:54:28 172.18.0.1 - - [11/Sep/2020:06:25:30 +0000] "GET /wss?authToken=ddaa4f9384347a9dd9cf43adafbedee2&userId=5d81fc47394db142f HTTP/1.1" 200 329 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:80.0) Gecko/20100101 Firefox/80.0"
    Sep 11 08:54:28 172.18.0.1 - - [11/Sep/2020:06:37:22 +0000] "GET /wss?authToken=1813560ebf60b4ae00cca88765c9f208&userId=5da5ac83185c2cb8a HTTP/1.1" 200 328 "-" "Mozilla/5.0 (Windows NT 6.3; Win64; x64; rv:80.0) Gecko/20100101 Firefox/80.0"
    Sep 11 08:54:28 2020-09-11 06:54:28,974 INFO stopped: ws (exit status 15)
    Sep 11 08:54:29 2020-09-11 06:54:29,120 INFO stopped: web (exit status 0)
    Sep 11 08:54:31 => Fixing up modules
    Sep 11 08:54:31 box:tasks 4621: {"percent":100,"message":"Done"}
    Sep 11 08:54:31 box:apptask crm.4pl-intermodal.com updating app with values: {"installationState":"installed","error":null,"health":null}
    Sep 11 08:54:31 box:taskworker Task took 2.544 seconds
    Sep 11 08:54:31 box:tasks setCompleted - 4621: {"result":null,"error":null}
    Sep 11 08:54:31 box:tasks 4621: {"percent":100,"result":null,"error":null}
    Sep 11 08:54:31 => update config
    Sep 11 08:54:31 => Data version is 5.9.3. Expecting 5.9.3
    Sep 11 08:54:31 => Up to date. Nothing to upgrade
    Sep 11 08:54:31 => Rebuild backend and clear cache
    Sep 11 08:54:33 => Running cron job
    Sep 11 08:54:37 => Starting EspoCRM
    Sep 11 08:54:37 2020-09-11 06:54:37,316 CRIT Supervisor running as root (no user in config file)
    Sep 11 08:54:37 2020-09-11 06:54:37,316 INFO Included extra file "/etc/supervisor/conf.d/web.conf" during parsing
    Sep 11 08:54:37 2020-09-11 06:54:37,316 INFO Included extra file "/etc/supervisor/conf.d/ws.conf" during parsing
    Sep 11 08:54:37 2020-09-11 06:54:37,336 INFO RPC interface 'supervisor' initialized
    Sep 11 08:54:37 2020-09-11 06:54:37,336 CRIT Server 'unix_http_server' running without any HTTP authentication checking
    Sep 11 08:54:37 2020-09-11 06:54:37,336 INFO supervisord started with pid 1
    Sep 11 08:54:38 2020-09-11 06:54:38,341 INFO spawned: 'web' with pid 36
    Sep 11 08:54:38 2020-09-11 06:54:38,349 INFO spawned: 'ws' with pid 37
    Sep 11 08:54:38 AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.18.0.4. Set the 'ServerName' directive globally to suppress this message
    Sep 11 08:54:38 httpd (pid 39) already running
    Sep 11 08:54:38 2020-09-11 06:54:38,631 INFO exited: web (exit status 0; not expected)
    Sep 11 08:54:39 2020-09-11 06:54:39,637 INFO spawned: 'web' with pid 41
    Sep 11 08:54:39 2020-09-11 06:54:39,639 INFO success: ws entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
    Sep 11 08:54:39 AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.18.0.4. Set the 'ServerName' directive globally to suppress this message
    Sep 11 08:54:39 httpd (pid 39) already running
    Sep 11 08:54:39 2020-09-11 06:54:39,859 INFO exited: web (exit status 0; not expected)
    Sep 11 08:54:41 2020-09-11 06:54:41,866 INFO spawned: 'web' with pid 43
    Sep 11 08:54:42 AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.18.0.4. Set the 'ServerName' directive globally to suppress this message
    Sep 11 08:54:42 httpd (pid 39) already running
    Sep 11 08:54:42 2020-09-11 06:54:42,087 INFO exited: web (exit status 0; not expected)
    Sep 11 08:54:45 2020-09-11 06:54:45,096 INFO spawned: 'web' with pid 45
    Sep 11 08:54:45 AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.18.0.4. Set the 'ServerName' directive globally to suppress this message
    Sep 11 08:54:45 httpd (pid 39) already running
    Sep 11 08:54:45 2020-09-11 06:54:45,315 INFO exited: web (exit status 0; not expected)
    Sep 11 08:54:46 2020-09-11 06:54:46,317 INFO gave up: web entered FATAL state, too many start retries too quickly
    

    The Terminal window is empty. I need to restart the whole Server.


  • Staff

    This looks like some wrong apache process state handling in the package. Can you open a terminal into the app and run rm /run/apache2/apache2.pid then supervisorctl restart web

    Ideally keep an eye on the logs while doing that.


  • Staff

    @jensbee4 said in EspoCRM doesn't come online after server reboot:

    The Terminal window is empty. I need to restart the whole Server.

    @jensbee4 Does this mean you got it working after you restarted the whole server?



  • @girish said in EspoCRM doesn't come online after server reboot:

    @jensbee4 Does this mean you got it working after you restarted the whole server?

    Yes, after restarting the Server Espo is available again.
    Today i got the same situation.
    Espo stopped responding. But now i entered supervisorctl restart web in the Terminal and Espo was available again.


Log in to reply