Let's Encrypt + Debian 8 + Nginx - Service not reloaded after cert renewal

Hi there,
I am looking for some troubleshooting advice. The setup looks as the following:
- Debian 8
- Certbot 0.10.2
- ISPC 3.1.11 (Master / Slave setup)
- Nginx

On two of our slaves where rarely config changes are done, we ran (independently) into a situation where the LE cert expired. After doing some research, we found out that the cert renewal works without any issues and the new certs were all around and symlinked correctly. But the nginx process was never reloaded / restarted afterwards and thus no new certs being delivered to the customer.
A simple service nginx restart made everything working again. Triggering any other action in ISPC that reloads / restarts the service also did the trick. On other machines we never stumbled upon this issue which was mainly because we do have regular site config updates which trigger the nginx restart anyway.

So as far as I were able to follow up: The ISPC LE Cron which is written in PHP seems to be working fine. Except of the service unit restart. Sadly I have no idea how to dig in deeper at this point.

I consider that this might be a timing issue looking at the cron Code:
https://git.ispconfig.org/ispconfig...ib/classes/cron.d/900-letsencrypt.inc.php#L69
Because if the restart indicator file is not there (synchronously) after the exec is done then no service restart will be performed. We did have runtimes of the LE renewal of several seconds (up to >10s). Depending on the amount of alias domains.

But this is just the only clue I could come up with. Any ideas or advices how to debug this further? Or are there known configs that might lead to such conditions (although I do not think so looking at the ISPC LE Cron source code)?

Thanks and best regards,
Jan

 

Thanks for your feedback Till.

I do (still ;-) ) believe that exec works that way too, but that's the only line of code that looks like something being able to cause this situation. And race conditions are always a PITA to debug...
Regarding Master / Slave. This is not a mirror Setup, it's just the Master as our control server running the interface with all the independent slaves being attached to it. The master does not have the same domains nor certs configured.

The next expected cert renewal run on one of the servers is in about two or three days, so I might give the sleep() a try then.
I also already considered the nginx restart by cron but disliked that solution. As this happens on two independent servers of ours, other ISPC users might also run into it. That's why I would prefer finding the issue and a "real" solution for it.

So if the sleep is everything I can try, I will get back to you in about three days, after the renewal run went through. If someone else comes up with others ideas, I am happy to put them into the code before the renewal happens.

Best,
Jan

 

Do you have any convenient logging mechanism in place at this point of code execution I can use to add the debug output?

 

And another question in this context:
If we assume the exec call being reliable sync (which I would expect at the moment) why the hassle with the le.restart file? If the exec call is done, there should be no problem in restarting the httpd in any case like it is done in the other occurences at the Cron. The only benefit I currently see would be to prevent the httpd from being restarted, if the LE renewal fails. And if this is intended, I would question why this isn't done at the other renewal calls.
Just something that came up my mind reading the code again.

//Edit: Thanks for the Log info!

 

Hi Till,
the run went through yesterday night as expected. Nginx wasn't restarted again... as expected.
I patched the ISPC LE Cron file ( /usr/local/ispconfig/server/lib/classes/cron.d/900-letsencrypt.inc.php - this is the correct file, isn't it?) like this and set the Log level for this Server to Debug via the ISPC Interface (I added the debug lines prefixed wit "LE-DEBUG"):

PHP:

$server_config = $app->getconf->get_server_config($conf['server_id'], 'server');
                if(!isset($server_config['migration_mode']) || $server_config['migration_mode'] != 'y') {
                        $letsencrypt = explode("\n", shell_exec('which letsencrypt certbot /root/.local/share/letsencrypt/bin/letsencrypt /opt/eff.org/certbot/venv/bin/certbot'));
                        $letsencrypt = reset($letsencrypt);
                        if(is_executable($letsencrypt)) {
                                $app->log('LE-DEBUG - Running LE Renewal', LOGLEVEL_DEBUG);
                                $version = exec($letsencrypt . ' --version  2>&1', $ret, $val);
                                if(preg_match('/^(\S+|\w+)\s+(\d+(\.\d+)+)$/', $version, $matches)) {
                                        $type = strtolower($matches[1]);
                                        $version = $matches[2];
                                        if(($type != 'letsencrypt' && $type != 'certbot') || version_compare($version, '0.7.0', '<')) {
                                                exec($letsencrypt . ' -n renew');
                                                $app->services->restartServiceDelayed('httpd', 'force-reload');
                                        } else {
                                                $app->log('LE-DEBUG - Writing LE Restart File', LOGLEVEL_DEBUG);
                                                $marker_file = '/usr/local/ispconfig/server/le.restart';
                                                $cmd = "echo '1' > " . $marker_file;
                                                exec($letsencrypt . ' -n renew --post-hook ' . escapeshellarg($cmd));
                                                $app->log('LE-DEBUG - Renew is done', LOGLEVEL_DEBUG);
                                                if(file_exists($marker_file) && trim(file_get_contents($marker_file)) == '1') {
                                                        unlink($marker_file);
                                                        $app->log('LE-DEBUG - Restarting HTTPD Service', LOGLEVEL_DEBUG);
                                                        $app->services->restartServiceDelayed('httpd', 'force-reload');
                                                }
                                                $app->log('LE-DEBUG - Everything done', LOGLEVEL_DEBUG);
                                        }
                                } else {
                                        exec($letsencrypt . ' -n renew');
                                        $app->services->restartServiceDelayed('httpd', 'force-reload');
                                }
                        }
                } else {
                        $app->log('Migration mode active, not running Let\'s Encrypt renewal.', LOGLEVEL_DEBUG);
                }


I then checked the time of the new LE Certs (28.04. - 21:20) and read the /var/log/ispconfig/ispconfig.log

There are only these two lines (over and over again but nothing else):
28.04.2018-21:21 - DEBUG - Calling function 'check_phpini_changes' from plugin 'webserver_plugin' raised by action 'server_plugins_loaded'.
28.04.2018-21:21 - DEBUG - Remove Lock: /usr/local/ispconfig/server/temp/.ispconfig_lock

From my current learnigns, it looks like the ISPC LE Cron file was never executed or I should have seen the log output...

Neither crontab nor cron.d / cron.daily contain any Letsencryt native Cronjobs. So I am a bit confused where the renewal call comes from at all...

I also checked for the LE executables but those look fine:
SERVER:/# which letsencrypt certbot /root/.local/share/letsencrypt/bin/letsencrypt /opt/eff.org/certbot/venv/bin/certbot
/usr/bin/letsencrypt
/usr/bin/certbot

SERVER:/# /usr/bin/letsencrypt -v
Root logging level set at 10
Saving debug log to /var/log/letsencrypt/letsencrypt.log
certbot version: 0.10.2
Arguments: ['-v']
...

SERVER:/# /usr/bin/certbot -v
Root logging level set at 10
Saving debug log to /var/log/letsencrypt/letsencrypt.log
certbot version: 0.10.2
Arguments: ['-v']
...

How can I check what might be wrong with the ISPC Crons? Any other ideas?

Thanks and have a sunny sunday,
Jan

 

Looks like there are two certbots and two let`s encrypts installed. This may cause issues.

 

Just checked: /usr/bin/letsencrypt is just a symlink to /usr/bin/certbot. Looks like a legacy failsafe.
So no, there is just one version installed.

Anyway it shouldn't matter as only one script is/should be called by the ISPC LE Cron.

Jan

 

Hi Till, any updates on your side?
We had this happening again and were only able to circumvent it using a cron with service nginx reload once each month.
Have a great weekend,
Jan