Bug 999722 - ipa cert-remove-hold <non-existent cert id> returns server error
ipa cert-remove-hold <non-existent cert id> returns server error
Status: CLOSED CURRENTRELEASE
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: pki-core (Show other bugs)
7.0
Unspecified Unspecified
unspecified Severity unspecified
: rc
: ---
Assigned To: Endi Sukma Dewata
Namita Soman
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2013-08-21 18:58 EDT by Michael Gregg
Modified: 2015-02-13 05:44 EST (History)
5 users (show)

See Also:
Fixed In Version: pki-core-10.0.5-2.el7
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2014-06-13 09:31:32 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Michael Gregg 2013-08-21 18:58:14 EDT
Description of problem:
Upon running "ipa cert-remove-hold <non-existent cert id>", the error
message "ERROR: an internal error has occurred" comes out.

Previously, upon running this command, ipa cert-remove-hold would only return
"Record not found"

I was not sure if I should open this bug against ipa or pki.

Version-Release number of selected component (if applicable):
ipa-server-3.3.0-7.el7.x86_64
pki-tools-10.0.4-1.el7.x86_64

How reproducible:
Always

Steps to Reproduce:
1. kinit as admin
2. ipa cert-remove-hold <non-existent cert id>

Actual results:
[root@ipaqa64vmd quickinstall]# ipa cert-remove-hold 8999
Aug 21, 2013 6:56:59 PM org.apache.catalina.core.ApplicationContext log
INFO: caDoUnrevoke: com.netscape.certsrv.base.PKIException: Record not found
{ <snip>
} 
ipa: ERROR: an internal error has occurred


Additional info:
When this is run, the following comes up in
/var/log/pki/pki-tomcat/host-manager.2013-08-21.log

"Aug 21, 2013 6:41:40 PM org.apache.catalina.core.ApplicationContext log
INFO: caDoUnrevoke: com.netscape.certsrv.base.PKIException: Record not found
    at com.netscape.cms.servlet.cert.DoUnrevoke.process(DoUnrevoke.java:277)
    at com.netscape.cms.servlet.cert.DoUnrevoke.process(DoUnrevoke.java:174)
    at com.netscape.cms.servlet.base.CMSServlet.service(CMSServlet.java:501)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:728)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at
org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:277)
    at
org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:274)
    at java.security.AccessController.doPrivileged(Native Method)
    at javax.security.auth.Subject.doAsPrivileged(Subject.java:536)
    at
org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:309)
    at
org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:169)
    at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:299)
    at
org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:57)
    at
org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:193)
    at
org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:189)
    at java.security.AccessController.doPrivileged(Native Method)
    at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
    at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
    at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
    at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472)
    at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
    at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:99)
    at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
    at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)
    at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:200)
    at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:589)
    at
org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:310)
    at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:724)

ipa: ERROR: an internal error has occurred
"
Comment 2 Rob Crittenden 2013-08-22 08:35:22 EDT
It seems to me like an issue with CS, cc'd Ade to see what he thinks.

Michael, was anything reported in /var/log/httpd/error_log? It may give more details on what was returned by CS.
Comment 3 Michael Gregg 2013-08-22 19:22:54 EDT
There is a error in the error_log.

Error message as follows:

[Thu Aug 22 19:08:28.424592 2013] [:error] [pid 7632] ipa: ERROR: non-public: XMLSyntaxError: AttValue: " or ' expected, line 2, column 14
[Thu Aug 22 19:08:28.424711 2013] [:error] [pid 7632] Traceback (most recent call last):
[Thu Aug 22 19:08:28.424731 2013] [:error] [pid 7632]   File "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 333, in wsgi_execute
[Thu Aug 22 19:08:28.424740 2013] [:error] [pid 7632]     result = self.Command[name](*args, **options)
[Thu Aug 22 19:08:28.424751 2013] [:error] [pid 7632]   File "/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 436, in __call__
[Thu Aug 22 19:08:28.424764 2013] [:error] [pid 7632]     ret = self.run(*args, **options)
[Thu Aug 22 19:08:28.424771 2013] [:error] [pid 7632]   File "/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 755, in run
[Thu Aug 22 19:08:28.424783 2013] [:error] [pid 7632]     result = self.execute(*args, **options)
[Thu Aug 22 19:08:28.424790 2013] [:error] [pid 7632]   File "/usr/lib/python2.7/site-packages/ipalib/plugins/cert.py", line 627, in execute
[Thu Aug 22 19:08:28.424796 2013] [:error] [pid 7632]     result=self.Backend.ra.take_certificate_off_hold(serial_number)
[Thu Aug 22 19:08:28.424809 2013] [:error] [pid 7632]   File "/usr/lib/python2.7/site-packages/ipaserver/plugins/dogtag.py", line 1713, in take_certificate_off_hold
[Thu Aug 22 19:08:28.424818 2013] [:error] [pid 7632]     parse_result = self.get_parse_result_xml(http_body, parse_unrevoke_cert_xml)
[Thu Aug 22 19:08:28.424830 2013] [:error] [pid 7632]   File "/usr/lib/python2.7/site-packages/ipaserver/plugins/dogtag.py", line 1365, in get_parse_result_xml
[Thu Aug 22 19:08:28.424838 2013] [:error] [pid 7632]     doc = etree.fromstring(xml_text, parser)
[Thu Aug 22 19:08:28.424845 2013] [:error] [pid 7632]   File "lxml.etree.pyx", line 2993, in lxml.etree.fromstring (src/lxml/lxml.etree.c:63070)
[Thu Aug 22 19:08:28.424852 2013] [:error] [pid 7632]   File "parser.pxi", line 1617, in lxml.etree._parseMemoryDocument (src/lxml/lxml.etree.c:93194)
[Thu Aug 22 19:08:28.424860 2013] [:error] [pid 7632]   File "parser.pxi", line 1495, in lxml.etree._parseDoc (src/lxml/lxml.etree.c:92003)
[Thu Aug 22 19:08:28.424870 2013] [:error] [pid 7632]   File "parser.pxi", line 1011, in lxml.etree._BaseParser._parseDoc (src/lxml/lxml.etree.c:88660)
[Thu Aug 22 19:08:28.424885 2013] [:error] [pid 7632]   File "parser.pxi", line 577, in lxml.etree._ParserContext._handleParseResultDoc (src/lxml/lxml.etree.c:84385)
[Thu Aug 22 19:08:28.424892 2013] [:error] [pid 7632]   File "parser.pxi", line 676, in lxml.etree._handleParseResult (src/lxml/lxml.etree.c:85488)
[Thu Aug 22 19:08:28.424899 2013] [:error] [pid 7632]   File "parser.pxi", line 616, in lxml.etree._raiseParseError (src/lxml/lxml.etree.c:84811)
[Thu Aug 22 19:08:28.424906 2013] [:error] [pid 7632] XMLSyntaxError: AttValue: " or ' expected, line 2, column 14
[Thu Aug 22 19:08:28.425486 2013] [:error] [pid 7632] ipa: INFO: admin@TESTRELM.COM: cert_remove_hold(u'8888', version=u'2.64'): XMLSyntaxError
ipa: ERROR: an internal error has occurred
Comment 4 Rob Crittenden 2013-08-22 23:06:07 EDT
I reproduced this using some random 3.x build I have in F-18 and pki-ca-10.0.3-1.fc18.noarch.

I believe the problem in this case is CS is HTML error but we expect an XML one:

[Thu Aug 22 22:32:10.782991 2013] [:error] [pid 3990] ipa: DEBUG: request headers {'date': 'Thu, 22 Aug 2013 12:32:10 GMT', 'vary': 'Accept-Encoding', 'content-length': '260', 'content-type': 'text/html; charset=UTF-8', 'server': 'Apache/2.4.4 (Fedora) mod_auth_kerb/5.4 mod_nss/2.4.2 NSS/3.13.5.0 PHP/5.4.15 mod_wsgi/3.4 Python/2.7.3 mod_perl/2.0.8-dev Perl/v5.16.3'}
[Thu Aug 22 22:32:10.783072 2013] [:error] [pid 3990] ipa: DEBUG: request body '<HTML>\\n<BODY BGCOLOR=white>\\n<P>\\nThe Certificate System has encountered an unrecoverable error.\\n<P>\\nError Message:<BR>\\n<I>com.netscape.certsrv.base.PKIException: Record not found</I>\\n<P>\\nPlease contact your local administrator for assistance.\\n</BODY>\\n</HTML>\\n\\r\\n'

We do an XML request though:

[Thu Aug 22 22:32:10.564775 2013] [:error] [pid 3990] ipa: INFO: request 'https://ipa.example.com:443/ca/agent/ca/doUnrevoke'
[Thu Aug 22 22:32:10.564819 2013] [:error] [pid 3990] ipa: DEBUG: request body 'xml=true&serialNumber=9999'

Re-assigning to pki-core package.
Comment 5 Nathan Kinder 2013-09-09 11:04:05 EDT
Upstream ticket:
https://fedorahosted.org/pki/ticket/739
Comment 6 Endi Sukma Dewata 2013-11-01 15:20:29 EDT
Fixed upstream.
Comment 8 Namita Soman 2013-12-09 13:33:55 EST
Verified using ipa-server-3.3.3-4,  pki-ca-10.0.5-2

Test output from automated run:

::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
:: [   LOG    ] :: cert_remove_hold_1003: remove-hold <invalid cert id> BZ999722
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

:: [ 13:54:59 ] ::  Test for invalid id: [9999], expected erorr msg: [Record not found]
ipa: ERROR: Certificate operation cannot be completed: ERROR (Record not found)
:: [   PASS   ] :: remove-hold an invalid cert failed as expected 
:: [ 13:55:01 ] ::  Test for invalid id: [abc], expected erorr msg: [Record not found]
ipa: ERROR: Certificate operation cannot be completed: ERROR (Record not found)
:: [   PASS   ] :: remove-hold an invalid cert failed as expected
Comment 9 Ludek Smid 2014-06-13 09:31:32 EDT
This request was resolved in Red Hat Enterprise Linux 7.0.

Contact your manager or support representative in case you have further questions about the request.

Note You need to log in before you can comment on or make changes to this bug.