From abbde8f1e7ae4622ce5662c5bf119004155e4838 Mon Sep 17 00:00:00 2001 From: brectanus Date: Fri, 15 Aug 2008 19:58:02 +0000 Subject: [PATCH] Added XML warn/error output to debug log. See #519. --- apache2/apache2.h | 4 + apache2/apache2_util.c | 39 +- apache2/re_operators.c | 12 + apache2/t/regression/rule/10-xml.t | 361 ++++++++++++++++++ .../server_root/conf/SoapEnvelope-bad.dtd | 8 + .../server_root/conf/SoapEnvelope-bad.xsd | 126 ++++++ .../server_root/conf/SoapEnvelope.dtd | 8 + .../server_root/conf/SoapEnvelope.xsd | 126 ++++++ 8 files changed, 682 insertions(+), 2 deletions(-) create mode 100644 apache2/t/regression/rule/10-xml.t create mode 100644 apache2/t/regression/server_root/conf/SoapEnvelope-bad.dtd create mode 100644 apache2/t/regression/server_root/conf/SoapEnvelope-bad.xsd create mode 100644 apache2/t/regression/server_root/conf/SoapEnvelope.dtd create mode 100644 apache2/t/regression/server_root/conf/SoapEnvelope.xsd diff --git a/apache2/apache2.h b/apache2/apache2.h index f82438e8..41efb200 100644 --- a/apache2/apache2.h +++ b/apache2/apache2.h @@ -92,6 +92,10 @@ void DSOLOCAL internal_log(request_rec *r, directory_config *dcfg, modsec_rec *m void DSOLOCAL msr_log(modsec_rec *msr, int level, const char *text, ...) PRINTF_ATTRIBUTE(3,4); +void DSOLOCAL msr_log_error(modsec_rec *msr, const char *text, ...) PRINTF_ATTRIBUTE(2,3); + +void DSOLOCAL msr_log_warn(modsec_rec *msr, const char *text, ...) PRINTF_ATTRIBUTE(2,3); + char DSOLOCAL *format_error_log_message(apr_pool_t *mp, error_message *em); const DSOLOCAL char *get_response_protocol(request_rec *r); diff --git a/apache2/apache2_util.c b/apache2/apache2_util.c index 19c7de84..bc3a5e89 100644 --- a/apache2/apache2_util.c +++ b/apache2/apache2_util.c @@ -245,6 +245,7 @@ void internal_log(request_rec *r, directory_config *dcfg, modsec_rec *msr, apr_size_t nbytes, nbytes_written; apr_file_t *debuglog_fd = NULL; int filter_debug_level = 0; + int str2len; char str1[1024] = ""; char str2[1256] = ""; @@ -262,13 +263,20 @@ void internal_log(request_rec *r, directory_config *dcfg, modsec_rec *msr, */ if ((level > 3)&&( (debuglog_fd == NULL) || (level > filter_debug_level) )) return; - /* Construct the message. */ + /* Construct the message (leaving a byte left for a newline if needed). */ apr_vsnprintf(str1, sizeof(str1), text, ap); - apr_snprintf(str2, sizeof(str2), "[%s] [%s/sid#%pp][rid#%pp][%s][%d] %s\n", + str2len = apr_snprintf(str2, sizeof(str2)-1, + "[%s] [%s/sid#%pp][rid#%pp][%s][%d] %s", current_logtime(msr->mp), ap_get_server_name(r), (r->server), r, ((r->uri == NULL) ? "" : log_escape_nq(msr->mp, r->uri)), level, str1); + /* Add a newline if there is not one already (needed for msr_log_*) */ + if (str2[str2len - 1] != '\n') { + str2[str2len] = '\n'; + str2[str2len + 1] = '\0'; + } + /* Write to the debug log. */ if ((debuglog_fd != NULL)&&(level <= filter_debug_level)) { nbytes = strlen(str2); @@ -321,6 +329,33 @@ void msr_log(modsec_rec *msr, int level, const char *text, ...) { } +/** + * Logs one message at level 3 to the debug log and to the + * Apache error log. This is intended for error callbacks. + */ +void msr_log_error(modsec_rec *msr, const char *text, ...) { + const char *str = text; + va_list ap; + + va_start(ap, text); + internal_log(msr->r, msr->txcfg, msr, 3, str, ap); + va_end(ap); +} + +/** + * Logs one message at level 4 to the debug log and to the + * Apache error log. This is intended for warning callbacks. + */ +void msr_log_warn(modsec_rec *msr, const char *text, ...) { + const char *str = text; + va_list ap; + + va_start(ap, text); + internal_log(msr->r, msr->txcfg, msr, 4, str, ap); + va_end(ap); +} + + /** * Converts an Apache error log message into one line of text. */ diff --git a/apache2/re_operators.c b/apache2/re_operators.c index 528968f9..a7a8eebc 100644 --- a/apache2/re_operators.c +++ b/apache2/re_operators.c @@ -891,6 +891,12 @@ static int msre_op_validateDTD_execute(modsec_rec *msr, msre_rule *rule, msre_va return -1; } + /* Send validator errors/warnings to msr_log */ + /* NOTE: No xmlDtdSetValidErrors()? */ + cvp->error = (xmlSchemaValidityErrorFunc)msr_log_error; + cvp->warning = (xmlSchemaValidityErrorFunc)msr_log_warn; + cvp->userData = msr; + if (!xmlValidateDtd(cvp, msr->xml->doc, dtd)) { *error_msg = "XML: DTD validation failed."; xmlFreeValidCtxt(cvp); @@ -935,6 +941,9 @@ static int msre_op_validateSchema_execute(modsec_rec *msr, msre_rule *rule, msre return -1; } + /* Send parser errors/warnings to msr_log */ + xmlSchemaSetParserErrors(parserCtx, (xmlSchemaValidityErrorFunc)msr_log_error, (xmlSchemaValidityWarningFunc)msr_log_warn, msr); + schema = xmlSchemaParse(parserCtx); if (schema == NULL) { *error_msg = apr_psprintf(msr->mp, "XML: Failed to load Schema: %s", rule->op_param); @@ -950,6 +959,9 @@ static int msre_op_validateSchema_execute(modsec_rec *msr, msre_rule *rule, msre return -1; } + /* Send validator errors/warnings to msr_log */ + xmlSchemaSetValidErrors(validCtx, (xmlSchemaValidityErrorFunc)msr_log_error, (xmlSchemaValidityWarningFunc)msr_log_warn, msr); + rc = xmlSchemaValidateDoc(validCtx, msr->xml->doc); if (rc != 0) { *error_msg = "XML: Schema validation failed."; diff --git a/apache2/t/regression/rule/10-xml.t b/apache2/t/regression/rule/10-xml.t new file mode 100644 index 00000000..9861457f --- /dev/null +++ b/apache2/t/regression/rule/10-xml.t @@ -0,0 +1,361 @@ +### Test for XML operator rules + +### Validate Scheme +# OK +{ + type => "rule", + comment => "validateSchema (validate ok)", + conf => qq( + SecRuleEngine On + SecRequestBodyAccess On + SecDebugLog $ENV{DEBUG_LOG} + SecDebugLogLevel 9 + SecRule REQUEST_HEADERS:Content-Type "^text/xml\$" \\ + "phase:1,t:none,t:lowercase,nolog,pass,ctl:requestBodyProcessor=XML" + SecRule REQBODY_PROCESSOR "!^XML\$" nolog,pass,skipAfter:12345 + SecRule XML "\@validateSchema $ENV{CONF_DIR}/SoapEnvelope.xsd" \\ + "phase:2,deny,id:12345" + ), + match_log => { + debug => [ qr/XML: Initialising parser.*XML: Parsing complete \(well_formed 1\).*Target value: "\[XML document tree\]".*Successfully validated payload against Schema/s, 1 ], + -debug => [ qr/XML parser error|validation failed|Failed to load/, 1 ], + -error => [ qr/XML parser error|validation failed|Failed to load/, 1 ], + }, + match_response => { + status => qr/^200$/, + }, + request => new HTTP::Request( + POST => "http://$ENV{SERVER_NAME}:$ENV{SERVER_PORT}/test.txt", + [ + "Content-Type" => "text/xml", + ], + normalize_raw_request_data( + q( + + + + + 12123 + + + + ), + ), + ), +}, +# Failed validation +{ + type => "rule", + comment => "validateSchema (validate failed)", + conf => qq( + SecRuleEngine On + SecRequestBodyAccess On + SecDebugLog $ENV{DEBUG_LOG} + SecDebugLogLevel 9 + SecRule REQUEST_HEADERS:Content-Type "^text/xml\$" \\ + "phase:1,t:none,t:lowercase,nolog,pass,ctl:requestBodyProcessor=XML" + SecRule REQBODY_PROCESSOR "!^XML\$" nolog,pass,skipAfter:12345 + SecRule XML "\@validateSchema $ENV{CONF_DIR}/SoapEnvelope.xsd" \\ + "phase:2,deny,id:12345" + ), + match_log => { + debug => [ qr/XML: Initialising parser.*XML: Parsing complete \(well_formed 1\).*Target value: "\[XML document tree\]".*element is not expected/s, 1 ], + -debug => [ qr/XML parser error|Failed to load/, 1 ], + -error => [ qr/XML parser error|Failed to load/, 1 ], + }, + match_response => { + status => qr/^403$/, + }, + request => new HTTP::Request( + POST => "http://$ENV{SERVER_NAME}:$ENV{SERVER_PORT}/test.txt", + [ + "Content-Type" => "text/xml", + ], + normalize_raw_request_data( + q( + + + + + 12123 + + + + ), + ), + ), +}, +# Bad XML +{ + type => "rule", + comment => "validateSchema (bad XML)", + conf => qq( + SecRuleEngine On + SecRequestBodyAccess On + SecDebugLog $ENV{DEBUG_LOG} + SecDebugLogLevel 9 + SecRule REQUEST_HEADERS:Content-Type "^text/xml\$" \\ + "phase:1,t:none,t:lowercase,nolog,pass,ctl:requestBodyProcessor=XML" + SecRule REQBODY_PROCESSOR "!^XML\$" nolog,pass,skipAfter:12345 + SecRule XML "\@validateSchema $ENV{CONF_DIR}/SoapEnvelope.xsd" \\ + "phase:2,deny,id:12345" + ), + match_log => { + debug => [ qr/XML: Initialising parser.*XML: Parsing complete \(well_formed 0\).*XML parser error/s, 1 ], + -debug => [ qr/Failed to load/, 1 ], + -error => [ qr/Failed to load/, 1 ], + }, + match_response => { + status => qr/^403$/, + }, + request => new HTTP::Request( + POST => "http://$ENV{SERVER_NAME}:$ENV{SERVER_PORT}/test.txt", + [ + "Content-Type" => "text/xml", + ], + normalize_raw_request_data( + q( + + + + + 12123 + + + + ), + ), + ), +}, +# Bad schema +{ + type => "rule", + comment => "validateSchema (bad schema)", + conf => qq( + SecRuleEngine On + SecRequestBodyAccess On + SecDebugLog $ENV{DEBUG_LOG} + SecDebugLogLevel 9 + SecRule REQUEST_HEADERS:Content-Type "^text/xml\$" \\ + "phase:1,t:none,t:lowercase,nolog,pass,ctl:requestBodyProcessor=XML" + SecRule REQBODY_PROCESSOR "!^XML\$" nolog,pass,skipAfter:12345 + SecRule XML "\@validateSchema $ENV{CONF_DIR}/SoapEnvelope-bad.xsd" \\ + "phase:2,deny,id:12345" + ), + match_log => { + debug => [ qr/XML: Initialising parser.*XML: Parsing complete \(well_formed 1\).*Target value: "\[XML document tree\]".*Failed to parse the XML resource.*Failed to load Schema/s, 1 ], + }, + match_response => { + status => qr/^200$/, + }, + request => new HTTP::Request( + POST => "http://$ENV{SERVER_NAME}:$ENV{SERVER_PORT}/test.txt", + [ + "Content-Type" => "text/xml", + ], + normalize_raw_request_data( + q( + + + + + 12123 + + + + ), + ), + ), +}, + +# Validate DTD +# OK +{ + type => "rule", + comment => "validateDTD (validate ok)", + conf => qq( + SecRuleEngine On + SecRequestBodyAccess On + SecDebugLog $ENV{DEBUG_LOG} + SecDebugLogLevel 9 + SecRule REQUEST_HEADERS:Content-Type "^text/xml\$" \\ + "phase:1,t:none,t:lowercase,nolog,pass,ctl:requestBodyProcessor=XML" + SecRule REQBODY_PROCESSOR "!^XML\$" nolog,pass,skipAfter:12345 + SecRule XML "\@validateDTD $ENV{CONF_DIR}/SoapEnvelope.dtd" \\ + "phase:2,deny,id:12345" + ), + match_log => { + debug => [ qr/XML: Initialising parser.*XML: Parsing complete \(well_formed 1\).*Target value: "\[XML document tree\]".*Successfully validated payload against DTD/s, 1 ], + -debug => [ qr/XML parser error|validation failed|Failed to load/, 1 ], + -error => [ qr/XML parser error|validation failed|Failed to load/, 1 ], + }, + match_response => { + status => qr/^200$/, + }, + request => new HTTP::Request( + POST => "http://$ENV{SERVER_NAME}:$ENV{SERVER_PORT}/test.txt", + [ + "Content-Type" => "text/xml", + ], + normalize_raw_request_data( + q( + + + + + + 12123 + + + + ), + ), + ), +}, +# Failed validation +{ + type => "rule", + comment => "validateDTD (validate failed)", + conf => qq( + SecRuleEngine On + SecRequestBodyAccess On + SecDebugLog $ENV{DEBUG_LOG} + SecDebugLogLevel 9 + SecRule REQUEST_HEADERS:Content-Type "^text/xml\$" \\ + "phase:1,t:none,t:lowercase,nolog,pass,ctl:requestBodyProcessor=XML" + SecRule REQBODY_PROCESSOR "!^XML\$" nolog,pass,skipAfter:12345 + SecRule XML "\@validateDTD $ENV{CONF_DIR}/SoapEnvelope.dtd" \\ + "phase:2,deny,id:12345" + ), + match_log => { + debug => [ qr/XML: Initialising parser.*XML: Parsing complete \(well_formed 1\).*Target value: "\[XML document tree\]".*content does not follow the DTD/s, 1 ], + -debug => [ qr/XML parser error|Failed to load/, 1 ], + -error => [ qr/XML parser error|Failed to load/, 1 ], + }, + match_response => { + status => qr/^403$/, + }, + request => new HTTP::Request( + POST => "http://$ENV{SERVER_NAME}:$ENV{SERVER_PORT}/test.txt", + [ + "Content-Type" => "text/xml", + ], + normalize_raw_request_data( + q( + + + + + + 12123 + + + + ), + ), + ), +}, +# Bad XML +{ + type => "rule", + comment => "validateDTD (bad XML)", + conf => qq( + SecRuleEngine On + SecRequestBodyAccess On + SecDebugLog $ENV{DEBUG_LOG} + SecDebugLogLevel 9 + SecRule REQUEST_HEADERS:Content-Type "^text/xml\$" \\ + "phase:1,t:none,t:lowercase,nolog,pass,ctl:requestBodyProcessor=XML" + SecRule REQBODY_PROCESSOR "!^XML\$" nolog,pass,skipAfter:12345 + SecRule XML "\@validateDTD $ENV{CONF_DIR}/SoapEnvelope.dtd" \\ + "phase:2,deny,id:12345" + ), + match_log => { + debug => [ qr/XML: Initialising parser.*XML: Parsing complete \(well_formed 0\).*XML parser error/s, 1 ], + -debug => [ qr/Failed to load/, 1 ], + -error => [ qr/Failed to load/, 1 ], + }, + match_response => { + status => qr/^403$/, + }, + request => new HTTP::Request( + POST => "http://$ENV{SERVER_NAME}:$ENV{SERVER_PORT}/test.txt", + [ + "Content-Type" => "text/xml", + ], + normalize_raw_request_data( + q( + + + + + + 12123 + + + + ), + ), + ), +}, +# Bad DTD +{ + type => "rule", + comment => "validateDTD (bad DTD)", + conf => qq( + SecRuleEngine On + SecRequestBodyAccess On + SecDebugLog $ENV{DEBUG_LOG} + SecDebugLogLevel 9 + SecRule REQUEST_HEADERS:Content-Type "^text/xml\$" \\ + "phase:1,t:none,t:lowercase,nolog,pass,ctl:requestBodyProcessor=XML" + SecRule REQBODY_PROCESSOR "!^XML\$" nolog,pass,skipAfter:12345 + SecRule XML "\@validateDTD $ENV{CONF_DIR}/SoapEnvelope-bad.dtd" \\ + "phase:2,deny,id:12345" + ), + match_log => { + debug => [ qr/XML: Initialising parser.*XML: Parsing complete \(well_formed 1\).*Target value: "\[XML document tree\]".*Failed to load DTD/s, 1 ], + }, + match_response => { + status => qr/^200$/, + }, + request => new HTTP::Request( + POST => "http://$ENV{SERVER_NAME}:$ENV{SERVER_PORT}/test.txt", + [ + "Content-Type" => "text/xml", + ], + normalize_raw_request_data( + q( + + + + + + 12123 + + + + ), + ), + ), +}, diff --git a/apache2/t/regression/server_root/conf/SoapEnvelope-bad.dtd b/apache2/t/regression/server_root/conf/SoapEnvelope-bad.dtd new file mode 100644 index 00000000..7d6c19f4 --- /dev/null +++ b/apache2/t/regression/server_root/conf/SoapEnvelope-bad.dtd @@ -0,0 +1,8 @@ + + + + + + + + diff --git a/apache2/t/regression/server_root/conf/SoapEnvelope-bad.xsd b/apache2/t/regression/server_root/conf/SoapEnvelope-bad.xsd new file mode 100644 index 00000000..2acfd1da --- /dev/null +++ b/apache2/t/regression/server_root/conf/SoapEnvelope-bad.xsd @@ -0,0 +1,126 @@ + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + Prose in the spec does not specify that attributes are allowed on the Body element + + + + + + + + + + + + + + + + + + + + 'encodingStyle' indicates any canonicalization conventions followed in the contents of the containing element. For example, the value 'http://schemas.xmlsoap.org/soap/encoding/' indicates the pattern described in SOAP specification + + + + + + + + + + + + + + + Fault reporting structure + + + + + + + + + + + + + + + + + + + + + + + + diff --git a/apache2/t/regression/server_root/conf/SoapEnvelope.dtd b/apache2/t/regression/server_root/conf/SoapEnvelope.dtd new file mode 100644 index 00000000..0ad4a8ab --- /dev/null +++ b/apache2/t/regression/server_root/conf/SoapEnvelope.dtd @@ -0,0 +1,8 @@ + + + + + + + + diff --git a/apache2/t/regression/server_root/conf/SoapEnvelope.xsd b/apache2/t/regression/server_root/conf/SoapEnvelope.xsd new file mode 100644 index 00000000..2b4a8c06 --- /dev/null +++ b/apache2/t/regression/server_root/conf/SoapEnvelope.xsd @@ -0,0 +1,126 @@ + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + Prose in the spec does not specify that attributes are allowed on the Body element + + + + + + + + + + + + + + + + + + + + 'encodingStyle' indicates any canonicalization conventions followed in the contents of the containing element. For example, the value 'http://schemas.xmlsoap.org/soap/encoding/' indicates the pattern described in SOAP specification + + + + + + + + + + + + + + + Fault reporting structure + + + + + + + + + + + + + + + + + + + + + + + +