ModSecurity: Rule processing failed.

[CanSpace]

Yet another ModSecurity thread...

So as per our other recent post, we've recently switched from our own customized version of the AtomiCorp rules to the OWASP rules provided by cPanel.

On all of our servers, /usr/local/apache/logs/error_log is filled with these:

[Mon Feb 09 18:51:54 2015] [error] [client xxxx] ModSecurity: Rule processing failed. [hostname "xxxx"] [uri "xxxx"] [unique_id "VNlIGsBjLFwAACtCD9YAAAAb"]
[Mon Feb 09 18:51:55 2015] [error] [client xxxx] ModSecurity: Geo Lookup: Failed to lock proc mutex: Identifier removed [hostname "xxxx"] [uri "/"] [unique_id "VNlIG8BjLFwAACp6PnUAAAAW"]
[Mon Feb 09 18:51:55 2015] [error] [client xxxx] ModSecurity: Geo Lookup: Failed to lock proc mutex: Identifier removed [hostname "xxxx"] [uri "/"] [unique_id "VNlIG8BjLFwAACp6PnUAAAAW"]
[Mon Feb 09 18:51:56 2015] [error] [client xxxx] ModSecurity: Rule processing failed. [hostname "xxxx"] [uri "xxxx"] [unique_id "VNlIHMBjLFwAACtGEKAAAAAJ"]
[Mon Feb 09 18:52:00 2015] [error] [client xxxx] ModSecurity: Rule processing failed. [hostname "xxxx"] [uri "xxxx"] [unique_id "VNlIIMBjLFwAACtKEY4AAAAL"]
[Mon Feb 09 18:52:01 2015] [error] [client xxxx] ModSecurity: Rule processing failed. [hostname "xxxx"] [uri "xxxx"] [unique_id "VNlIIcBjLFwAACviGXEAAAAG"]
[Mon Feb 09 18:52:01 2015] [error] [client xxxx] ModSecurity: Rule processing failed. [hostname "xxxx"] [uri "xxxx"] [unique_id "VNlIIcBjLFwAACviGXIAAAAG"]

This particular server is a brand new server with a fresh copy of cPanel, and actually never had the AtomiCorp rules in place to begin with - we just installed the OWASP as a "ModSecurity Vendor". If I click the ModSecurity Tools link I do see a ton of hits being processed correctly... so I'm not sure what's going on here.

I have a ticket open with cPanel - they cleared our custom whitelist but the errors persist, so they've escalated the ticket.

This is happening on all our servers - so I can't imaging we're the only ones having this issue...

 

[quizknows]

It's an issue with the OWASP rules. I don't think anyone has figured this one out yet, but it's been mentioned in other threads. I seem to see it a lot right after a rule successfully blocks a request.

 

[CanSpace]

Really? Our error_log files are literally full of these errors. Not to mention they are also filling up the modsec_audit.log files which are growing massively large...

 

[quizknows]

At this point, I'm only enabling the OWASP rules long enough to troubleshoot things that I can. Once I'm done messing with them I'm turning them off and reverting to my custom rule set.

Unfortunately, even with the audit log data (which is very verbose, and really nice to have most of the time) I'm unable to find out why this error is showing up so much in the logs. Someone who maintains the OWASP rules is going to have to debug this one; I'm seeing it even on pretty benign GET requests. The audit log data doesn't even contain a rule ID to see what rule is causing the problem as far as I can tell.

I do believe there is something in the works to manage the audit logs; the audit log used to get cleared hourly prior to 11.46, but the newer hits log in WHM which uses a database to store the log entries (and is a great improvement over the old GUI interface) has deprecated the script modsecparse.pl which used to truncate the plain text audit log.

 

[kernow]

Looks like in cpanel 11.48.11 this problem is fixed.

 

[filoucp]

Looks like in cpanel 11.48.11 this problem is fixed.

Just updated to cpanel 11.48.11 and reactivated rules and "ModSecurity: Rule processing failed" is still filling up error_log.

 

[cPanelPeter]

Hello,

Do you happen to have ModRuid2 enabled? If so, could you please try disabling it (run EasyApache and disable ModRuid2) and see if the issue persists?

 

[quizknows]

I am not using Ruid2 on my servers and see the same log entries if I enable the OWASP rules.

 

[sonicthoughts]

This is a VERY SERIOUS ISSUE. Every apache call is hitting the GEOIP db and failing. Server can get to a halt under modest load. Very hard to debug this. YES, am using ruid2.

ModSecurity: collection_store: Failed to access DBM file "/var/cpanel/secdatadir/ip": Permission denied
ModSecurity: Geo Lookup: Failed to lock proc mutex: Permission denied

 

[sonicthoughts]

I found some discussions here: https://github.com/SpiderLabs/ModSecurity/issues/564 and a workaround:
https://github.com/SpiderLabs/ModSecurity/issues/426 - but not sure how to implement

 

[cPMatthewV]

Hello,

We understand that this is a serious issue and we are presently looking into this. We have recently opened case # 163393 to investigate this behavior and issue. Unfortunately I do not have an ETA as to when this will be resolved however you may review our changelog at http://changelog.cpanel.net to see when this is addressed.

 

[quizknows]

The error "Failed to access DBM file "/var/cpanel/secdatadir/ip": Permission denied" is going to be RUID2 related. In short, it's likely because the apache processes run as different users, causing permissions conflicts on this file.

The general error for Rule processing failed does not seem to be RUID2 related.

 

[sonicthoughts]

I think there are several problems related to this. Also, it may NOT be related to RUID2. It may be that the directory name is not correct (I cant find where it is set.) OR that apache is trying to open a location outside the permitted directory (ie. not in permitted htdocs for user.)

@cPMatthewV - each failed call takes .6ms and there are 3 per URL request. that adds up to a lot of waste (+logging, etc.) Pls. reference this thread (not sure how to see case # 163393 status ....)

More discussions here:
http://forums.cpanel.net/f185/modsecurity-collection_store-failed-access-dbm-file-417491.html
ModSecurity error - Hosting Security and Technology - Web Hosting Talk

BTW - I bet YOUR support costs would go WAY down if you bundled trustwave or atomic rules and support

 

[quizknows]

the setting that makes the SecDataDir /var/cpanel/secdatadir is in modsec2.cpanel.conf now (as of 11.46 or 11.48).

Ruid2 will have problems writing to it. The first user that makes an entry will "own" the file and then other users sites will have issues... That's if it can make the file to begin with. It appears cPanel makes the directory as root:nobody 770 with a sticky bit, so with apache not running as "nobody" under RUID2, it might not be able to store collections there at all.

ModSecrutiy previously had issues with audit logging because of the same ruid2 behavior, but that was fixed by creating separate files for the audit log entries (concurrent instead of serial) as set in modsec2.conf:

<IfModule mod_ruid2.c>
SecAuditLogStorageDir /usr/local/apache/logs/modsec_audit
SecAuditLogType Concurrent
</IfModule>

I wonder if ModSecurity could handle collections differently to make separate files similarly to this solution. I don't know if it has the capability to do so at this point.

 

[wrender]

We are getting the same error when using mod_fcgid.

Message: Rule processing failed.
Apache-Handler: fcgid-script
Stopwatch: 1423690559791324 181020 (- - -)
Stopwatch2: 1423690559791324 181020; combined=3950, p1=197, p2=3518, p3=0, p4=0, p5=153, sr=38, sw=82, l=0, gc=0
Producer: ModSecurity for Apache/2.8.0 (http://www.modsecurity.org/); OWASP_CRS/3.0.0.
Server: Apache
Engine-Mode: "ENABLED"

 

[wrender]

This is a VERY SERIOUS ISSUE. Every apache call is hitting the GEOIP db and failing. Server can get to a halt under modest load. Very hard to debug this. YES, am using ruid2.

ModSecurity: collection_store: Failed to access DBM file "/var/cpanel/secdatadir/ip": Permission denied
ModSecurity: Geo Lookup: Failed to lock proc mutex: Permission denied

Sonicthoughts I think your issue is different than the rule processing failed issue. I think for your issue may have a permission problem on your server. Maybe try altering your permissions on that folder/files, and then restart Apache. On ours this folder is:

drwxrwxr--   2 root     nobody            4096 Feb  5 09:47 secdatadir

and inside the folder:

-rwxrwxr--   1 nobody nobody           0 Feb  5 09:47 global.dir
-rwxrwxr--   1 nobody nobody           0 Feb  5 09:47 global.pag
-rwxrwxr--   1 nobody nobody     1835008 Feb 14 11:41 ip.dir
-rwxrwxr--   1 nobody nobody 13417314304 Feb 14 12:08 ip.pag

Also, make sure you have a tmp folder defined in your modsec2.user.conf that is writable by the web server: For example ours is:

SecTmpDir /usr/local/apache/conf/sec-tmp

 

[keat63]

Is there a particular rule causing this, that can be disabled until a fix comes out.
I too have apache logs filling up.

 

[quizknows]

wrender, the problem is with RUID2 files like ip.dir used for collections will be created by a user account rather than "nobody" due to ruid2 running apache as the vhost owner. When other vhosts try to access the files they cannot do so. This was an issue previously with audit logs but was fixed by using concurrent rather than serial audit logging (making separate audit log files that each user owns).

The "rule processing failed" appears to be a separate issue that is not related to RUID2.

 

[wrender]

Ok. Thanks for clarifying quizknows. We are running mod_fcgid , with suExec but these files seem to be created as nobody on our system.

 

[quizknows]

Yes, because Apache itself still runs as "nobody" despite using user-specific PHP handling, so it can handle the logging. Same with SuPHP. Collections work fine with those handlers.