Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

mod_md error: error loading staged set #223

Closed
EIKAInc opened this issue Aug 8, 2020 · 8 comments
Closed

mod_md error: error loading staged set #223

EIKAInc opened this issue Aug 8, 2020 · 8 comments

Comments

@EIKAInc
Copy link

EIKAInc commented Aug 8, 2020

Dear author and community! Thanks for all your work. I really appreciate it! But sadly I come across with new issue. From time to time Apache shut down accidentally. And I can't run it again.

In error_log I see:

[mpm_winnt:notice] [pid 5880:tid 476] AH00455: Apache/2.4.43 (Win64) OpenSSL/1.1.1g configured -- resuming normal operations
[mpm_winnt:notice] [pid 5880:tid 476] AH00456: Apache Lounge VS16 Server built: Apr 21 2020 16:23:13
[core:notice] [pid 5880:tid 476] AH00094: Command line: 'D:\\Apache\\bin\\httpd.exe -d D:/Apache'
[mpm_winnt:notice] [pid 5880:tid 476] AH00418: Parent: Created child process 6604
[md:error] [pid 6604:tid 380] (OS 80)The file exists.  : AH10069: domain.dom: error loading staged set
[:notice] [pid 6604:tid 380] ModSecurity for Apache/2.9.3 (http://www.modsecurity.org/) configured.
[:notice] [pid 6604:tid 380] ModSecurity: APR compiled version="1.7.0"; loaded version="1.7.0"
[:notice] [pid 6604:tid 380] ModSecurity: PCRE compiled version="8.43 "; loaded version="8.44 2020-02-12"
[:warn] [pid 6604:tid 380] ModSecurity: Loaded PCRE do not match with compiled!
[:notice] [pid 6604:tid 380] ModSecurity: LUA compiled version="Lua 5.2"
[:notice] [pid 6604:tid 380] ModSecurity: YAJL compiled version="2.1.0"
[:notice] [pid 6604:tid 380] ModSecurity: LIBXML compiled version="2.9.9"
[:notice] [pid 6604:tid 380] ModSecurity: StatusEngine call: "2.9.3,Apache/2.4.43 (Win64) Ope,1.7.0/1.7.0,8.43/8.44 2020-02-12,Lua 5.2,2.9.9,65f95f630f5ad88de1f990817976146c35130ef4"
[:notice] [pid 6604:tid 380] ModSecurity: StatusEngine call successfully sent. For more information visit: http://status.modsecurity.org/
[md:error] [pid 6604:tid 380] (OS 80)The file exists.  : AH10069: domain.dom: error loading staged set
[mpm_winnt:notice] [pid 6604:tid 380] AH00354: Child: Starting 150 worker threads.

The problem is definitely caused by mod_md, and related error_log record is:

AH10069: domain.dom: error loading staged set

I Googled for it, and found only mod_md source code:

+static void load_stage_sets(apr_array_header_t *names, apr_pool_t *p,
+                            md_reg_t *reg, server_rec *s)
+{
+    const char *name;
+    apr_status_t rv;
+    int i;
+   
+    for (i = 0; i < names->nelts; ++i) {
+        name = APR_ARRAY_IDX(names, i, const char*);
+        if (APR_SUCCESS == (rv = md_reg_load(reg, name, p))) {
+            ap_log_error( APLOG_MARK, APLOG_INFO, rv, s, APLOGNO(10068)
+                         "%s: staged set activated", name);
+        }
+        else if (!APR_STATUS_IS_ENOENT(rv)) {
+            ap_log_error( APLOG_MARK, APLOG_ERR, rv, s, APLOGNO(10069)
+                         "%s: error loading staged set", name);
+        }
+    }
+    return;

I am not sure that it does matter, but I have HTTP2 disabled (all lines are commended out):

#LoadModule http2_module modules/mod_http2.so
...
...
# <IfModule http2_module>
#    ProtocolsHonorOrder On
#    Protocols h2 h2c http/1.1
# </IfModule>

And my SSL config is:

Listen 443

SSLPassPhraseDialog  builtin
SSLSessionCache        "shmcb:${SRVROOT}/logs/ssl_scache(512000)"

SSLSessionCacheTimeout  300

SSLProtocol all -SSLv2 -SSLv3
SSLHonorCipherOrder on
SSLCipherSuite "EECDH+ECDSA+AESGCM EECDH+aRSA+AESGCM EECDH+ECDSA+SHA384 EECDH+ECDSA+SHA256 EECDH+aRSA+SHA384 EECDH+aRSA+SHA256 EECDH+aRSA+RC4 EECDH EDH+aRSA RC4 !aNULL !eNULL !LOW !3DES !MD5 !EXP !PSK !SRP !DSS !RC4"

MDCertificateAuthority https://acme-v02.api.letsencrypt.org/directory
MDCertificateAgreement accepted
MDRenewWindow 31d
MDNotifyCmd "d:/Apache/bin/mod_md.bat"

MDomain domain.dom www.domain.dom
<VirtualHost *:443>
    ServerName domain.dom
    ServerAlias www.domain.dom
...
...
...
</VirtualHost>

MDomain dev.domain.dom www.dev.domain.dom
<VirtualHost *:443>
    ServerName dev.domain.dom
    ServerAlias www.dev.domain.dom
...
...
...
</VirtualHost>

Any ideas what can cause this issue? I am not programmer and can't understand all the logic. But I want to solve this issue.

Please advise!

@icing
Copy link
Owner

icing commented Aug 10, 2020

Thanks for the details.

First of all, the error reported by mod_md is not preventing your Apache from running. This cannot be the cause of your Apache "shutting down accidentally".

Second, the error happens when a new certificate is activated, e.g. the directory from 'staging' is moved to 'domains'. The existing from 'domains' is moved to 'archive'. Just to explain what is happening.

If you can reproduce this, you can configure LogLevel md:trace2 to get more information in your error log where we can see what exactly is going wrong.

Since you are running under Windows, the obligatory question is: do you have a virus scanner installed?

Thanks for you help.

@EIKAInc
Copy link
Author

EIKAInc commented Aug 10, 2020

Hi icing!

Thanks for your reply.

Let me clarify. I am not trying to start or stop Apache. Apache stops accidentally and cannot run back again. Meanwhile, my mod_md.bat file starts sending me tons of emails (this but bile have a line to send email just one). It means that .bat files runs in a loop. This situation can be over only manually, but httpd process termination via Task Manager.

All of these things pointing to mod_md.

I can reproduce this error even when I change MDRenewWindow to 89 or something. Just to force Apache to update certificates in day or something. I don't know how to force cert renewal including MDNotifyCmd execution.

I will add LogLevel md:trace2, it's not a problem. But I don't know when certs renewal procedure will be attempted.

I have no any AV software active in background, but I scan this machine on demand. So, AV software cannot control (scan, move, delete, lock, etc.) any files / processes.

@EIKAInc
Copy link
Author

EIKAInc commented Aug 11, 2020

The same errors appears when Apache restarts normally (no freezes, restart initiated by sysop):

[Mon Aug 10 22:16:26.300719 2020] [mpm_winnt:notice] [pid 1284:tid 476] AH00424: Parent: Received restart signal -- Restarting the server.
[Mon Aug 10 22:16:26.650739 2020] [md:error] [pid 1284:tid 476] (OS 80)The file exists.  : AH10069: domain.dom: error loading staged set
[Mon Aug 10 22:16:26.750745 2020] [mpm_winnt:notice] [pid 1284:tid 476] AH00455: Apache/2.4.43 (Win64) OpenSSL/1.1.1g Apache/1.3.42 (Linux 2.4.x) configured -- resuming normal operations
[Mon Aug 10 22:16:26.750745 2020] [mpm_winnt:notice] [pid 1284:tid 476] AH00456: Apache Lounge VS16 Server built: Apr 21 2020 16:23:13
[Mon Aug 10 22:16:26.750745 2020] [core:notice] [pid 1284:tid 476] AH00094: Command line: 'D:\\Apache\\bin\\httpd.exe -d D:/Apache'
[Mon Aug 10 22:16:26.751745 2020] [mpm_winnt:notice] [pid 1284:tid 476] AH00418: Parent: Created child process 5732
[Mon Aug 10 22:16:27.109765 2020] [md:error] [pid 5732:tid 380] (OS 80)The file exists.  : AH10069: domain.dom: error loading staged set
[Mon Aug 10 22:16:27.116766 2020] [:notice] [pid 5732:tid 380] ModSecurity for Apache/2.9.3 (http://www.modsecurity.org/) configured.
[Mon Aug 10 22:16:27.116766 2020] [:notice] [pid 5732:tid 380] ModSecurity: APR compiled version="1.7.0"; loaded version="1.7.0"
[Mon Aug 10 22:16:27.116766 2020] [:notice] [pid 5732:tid 380] ModSecurity: PCRE compiled version="8.43 "; loaded version="8.44 2020-02-12"
[Mon Aug 10 22:16:27.116766 2020] [:warn] [pid 5732:tid 380] ModSecurity: Loaded PCRE do not match with compiled!
[Mon Aug 10 22:16:27.116766 2020] [:notice] [pid 5732:tid 380] ModSecurity: LUA compiled version="Lua 5.2"
[Mon Aug 10 22:16:27.116766 2020] [:notice] [pid 5732:tid 380] ModSecurity: YAJL compiled version="2.1.0"
[Mon Aug 10 22:16:27.116766 2020] [:notice] [pid 5732:tid 380] ModSecurity: LIBXML compiled version="2.9.9"
[Mon Aug 10 22:16:27.182769 2020] [:notice] [pid 5732:tid 380] ModSecurity: StatusEngine call: "2.9.3,Apache/2.4.43 (Win64) Ope,1.7.0/1.7.0,8.43/8.44 2020-02-12,Lua 5.2,2.9.9,65f95f630f5ad88fd1f990817976146c35130ef4"
[Mon Aug 10 22:16:27.454785 2020] [:notice] [pid 5732:tid 380] ModSecurity: StatusEngine call successfully sent. For more information visit: http://status.modsecurity.org/
[Mon Aug 10 22:16:27.631795 2020] [md:error] [pid 5732:tid 380] (OS 80)The file exists.  : AH10069: domain.dom: error loading staged set
[Mon Aug 10 22:16:27.675798 2020] [mpm_winnt:notice] [pid 5732:tid 380] AH00354: Child: Starting 150 worker threads.
[Mon Aug 10 22:16:28.304834 2020] [mpm_winnt:notice] [pid 2752:tid 380] AH00364: Child: All worker threads have exited.

Maybe I need to clean some MD files manually? Because /md/ subfolders content is a bit different. E.g. /md/staging/ folder contains only subfolder domain.dom, but not dev.domain.dom. Meanwhile, /tmp/dev.domain.dom contains only job.json file, when /tmp/domain.dom contais 4 files (2 .json and 2 .pem files).

Could it be a reason of errors?

@EIKAInc
Copy link
Author

EIKAInc commented Sep 23, 2020

Problem was solved! It was write permission issue for mod_md files and folders:

X:\Apache\md\accounts\
X:\Apache\md\archive\
X:\Apache\md\challenges\
X:\Apache\md\domains\
X:\Apache\md\ocsp\
X:\Apache\md\staging\
X:\Apache\md\tmp\
X:\Apache\md\httpd.json
X:\Apache\md\md_store.json

It was a read / list or something. I added write and full, and problem has gone.

@EIKAInc EIKAInc closed this as completed Sep 23, 2020
@EIKAInc
Copy link
Author

EIKAInc commented Apr 6, 2021 via email

@icing
Copy link
Owner

icing commented Apr 6, 2021

Yes, if you delete the files in md/domains/<yourdomain> and reload the server, the module will renew immediately.

@EIKAInc
Copy link
Author

EIKAInc commented Apr 6, 2021 via email

@MatthiasPortzel
Copy link

I'm going to leave a comment here mostly for myself because I've hit this error message a couple of times before and this page comes up first in a search. I tried a couple of things to get it "unstuck." (Including deleting md/domains/example.com and md/staging/example.com.) I think what ended up working was editing the 000-example.com.conf file and restarting. (I commented out some reverse proxy lines, but after re-adding them the issue doesn't reproduce, so I don't think it was an actual configuration issue.)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants