RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1257518 - Running ipa-server-install produces 400 Bad Request in dogtag's access log
Summary: Running ipa-server-install produces 400 Bad Request in dogtag's access log
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: pki-core
Version: 7.2
Hardware: Unspecified
OS: Unspecified
low
low
Target Milestone: rc
: 7.3
Assignee: Fraser Tweedale
QA Contact: Asha Akkiangady
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2015-08-27 09:06 UTC by Jan Pazdziora
Modified: 2020-10-04 21:04 UTC (History)
9 users (show)

Fixed In Version: pki-core-10.3.1-1.el7
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2016-11-04 05:19:40 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github dogtagpki pki issues 2286 0 None closed Running ipa-server-install produces 400 Bad Request in dogtag's access log 2021-02-10 09:02:34 UTC
Red Hat Product Errata RHBA-2016:2396 0 normal SHIPPED_LIVE pki-core bug fix and enhancement update 2016-11-03 13:55:03 UTC

Description Jan Pazdziora 2015-08-27 09:06:32 UTC
Description of problem:

After running ipa-server-install, /var/log/pki/pki-tomcat/localhost_access_log.2015-*.txt contains

10.16.96.106 - ipara [27/Aug/2015:04:50:19 -0400] "POST /ca/rest/profiles/raw HTTP/1.1" 400 148

Version-Release number of selected component (if applicable):

ipa-server-4.2.0-5.el7.x86_64

How reproducible:

Deterministic.

Steps to Reproduce:
1. Run ipa-server-install.
2. Check /var/log/pki/pki-tomcat/localhost_access_log.2015-*.txt.

Actual results:

10.16.96.106 - - [27/Aug/2015:04:48:43 -0400] "GET /ca/admin/ca/getStatus HTTP/1.1" 200 167
10.16.96.106 - - [27/Aug/2015:04:50:17 -0400] "GET /ca/admin/ca/getStatus HTTP/1.1" 200 167
10.16.96.106 - ipara [27/Aug/2015:04:50:18 -0400] "GET /ca/rest/account/login HTTP/1.1" 200 205
10.16.96.106 - ipara [27/Aug/2015:04:50:18 -0400] "POST /ca/rest/profiles/raw HTTP/1.1" 201 7333
10.16.96.106 - ipara [27/Aug/2015:04:50:18 -0400] "POST /ca/rest/profiles/IECUserRoles?action=enable HTTP/1.1" 204 -
10.16.96.106 - ipara [27/Aug/2015:04:50:19 -0400] "GET /ca/rest/account/logout HTTP/1.1" 204 -
10.16.96.106 - ipara [27/Aug/2015:04:50:19 -0400] "GET /ca/rest/account/login HTTP/1.1" 200 205
10.16.96.106 - ipara [27/Aug/2015:04:50:19 -0400] "POST /ca/rest/profiles/raw HTTP/1.1" 400 148
10.16.96.106 - ipara [27/Aug/2015:04:50:20 -0400] "POST /ca/rest/profiles/caIPAserviceCert?action=disable HTTP/1.1" 204 -
10.16.96.106 - ipara [27/Aug/2015:04:50:20 -0400] "DELETE /ca/rest/profiles/caIPAserviceCert HTTP/1.1" 204 -
10.16.96.106 - ipara [27/Aug/2015:04:50:20 -0400] "POST /ca/rest/profiles/raw HTTP/1.1" 201 7008
10.16.96.106 - ipara [27/Aug/2015:04:50:20 -0400] "POST /ca/rest/profiles/caIPAserviceCert?action=enable HTTP/1.1" 204 -
10.16.96.106 - ipara [27/Aug/2015:04:50:20 -0400] "GET /ca/rest/account/logout HTTP/1.1" 204 -
10.16.96.106 - - [27/Aug/2015:04:50:21 -0400] "POST /ca/ee/ca/profileSubmitSSLClient HTTP/1.1" 200 1695
10.16.96.106 - - [27/Aug/2015:04:50:38 -0400] "GET /ca/admin/ca/getStatus HTTP/1.1" 200 167
10.16.96.106 - - [27/Aug/2015:04:50:43 -0400] "POST /ca/ee/ca/profileSubmitSSLClient HTTP/1.1" 200 1695
10.16.96.106 - - [27/Aug/2015:04:50:44 -0400] "POST /ca/ee/ca/profileSubmitSSLClient HTTP/1.1" 200 1292
10.16.96.106 - - [27/Aug/2015:04:52:20 -0400] "GET /ca/admin/ca/getStatus HTTP/1.1" 200 167
10.16.96.106 - - [27/Aug/2015:04:53:05 -0400] "GET /ca/admin/ca/getStatus HTTP/1.1" 200 167

Expected results:

No status 400 there.

Additional info:

The /var/log/ipaserver-install.log says

2015-08-27T08:50:19Z DEBUG request 'https://cloud-qe-9.idmqe.lab.eng.bos.redhat.com:8443/ca/rest/profiles/raw'
2015-08-27T08:50:19Z DEBUG request body 'profileId=caIPAserviceCert\nclassId=caEnrollImpl\ndesc=This certificate profile is for enrolling server certificate
s with IPA-RA agent authentication.\nvisible=false\nenable=true\nenableBy=admin\nauth.instance_id=raCertAuth\nname=IPA-RA Agent-Authenticated Server Certifi
cate Enrollment\ninput.list=i1,i2\ninput.i1.class_id=certReqInputImpl\ninput.i2.class_id=submitterInfoInputImpl\noutput.list=o1\noutput.o1.class_id=certOutp
utImpl\npolicyset.list=serverCertSet\npolicyset.serverCertSet.list=1,2,3,4,5,6,7,8,9,10,11\npolicyset.serverCertSet.1.constraint.class_id=subjectNameConstra
intImpl\npolicyset.serverCertSet.1.constraint.name=Subject Name Constraint\npolicyset.serverCertSet.1.constraint.params.pattern=CN=[^,]+,.+\npolicyset.serve
rCertSet.1.constraint.params.accept=true\npolicyset.serverCertSet.1.default.class_id=subjectNameDefaultImpl\npolicyset.serverCertSet.1.default.name=Subject 
Name Default\npolicyset.serverCertSet.1.default.params.name=CN=$request.req_subject_name.cn$, O=TESTRELM.TEST\npolicyset.serverCertSet.2.constraint.class_id
=validityConstraintImpl\npolicyset.serverCertSet.2.constraint.name=Validity Constraint\npolicyset.serverCertSet.2.constraint.params.range=740\npolicyset.ser
verCertSet.2.constraint.params.notBeforeCheck=false\npolicyset.serverCertSet.2.constraint.params.notAfterCheck=false\npolicyset.serverCertSet.2.default.clas
s_id=validityDefaultImpl\npolicyset.serverCertSet.2.default.name=Validity Default\npolicyset.serverCertSet.2.default.params.range=731\npolicyset.serverCertS
et.2.default.params.startTime=0\npolicyset.serverCertSet.3.constraint.class_id=keyConstraintImpl\npolicyset.serverCertSet.3.constraint.name=Key Constraint\n
policyset.serverCertSet.3.constraint.params.keyType=RSA\npolicyset.serverCertSet.3.constraint.params.keyParameters=1024,2048,3072,4096\npolicyset.serverCert
Set.3.default.class_id=userKeyDefaultImpl\npolicyset.serverCertSet.3.default.name=Key Default\npolicyset.serverCertSet.4.constraint.class_id=noConstraintImp
l\npolicyset.serverCertSet.4.constraint.name=No Constraint\npolicyset.serverCertSet.4.default.class_id=authorityKeyIdentifierExtDefaultImpl\npolicyset.serve
rCertSet.4.default.name=Authority Key Identifier Default\npolicyset.serverCertSet.5.constraint.class_id=noConstraintImpl\npolicyset.serverCertSet.5.constrai
nt.name=No Constraint\npolicyset.serverCertSet.5.default.class_id=authInfoAccessExtDefaultImpl\npolicyset.serverCertSet.5.default.name=AIA Extension Default
\npolicyset.serverCertSet.5.default.params.authInfoAccessADEnable_0=true\npolicyset.serverCertSet.5.default.params.authInfoAccessADLocationType_0=URIName\np
olicyset.serverCertSet.5.default.params.authInfoAccessADLocation_0=http://ipa-ca.testrelm.test/ca/ocsp\npolicyset.serverCertSet.5.default.params.authInfoAccessADMethod_0=1.3.6.1.5.5.7.48.1\npolicyset.serverCertSet.5.default.params.authInfoAccessCritical=false\npolicyset.serverCertSet.5.default.params.authInfoAccessNumADs=1\npolicyset.serverCertSet.6.constraint.class_id=keyUsageExtConstraintImpl\npolicyset.serverCertSet.6.constraint.name=Key Usage Extension Constraint\npolicyset.serverCertSet.6.constraint.params.keyUsageCritical=true\npolicyset.serverCertSet.6.constraint.params.keyUsageDigitalSignature=true\npolicyset.serverCertSet.6.constraint.params.keyUsageNonRepudiation=true\npolicyset.serverCertSet.6.constraint.params.keyUsageDataEncipherment=true\npolicyset.serverCertSet.6.constraint.params.keyUsageKeyEncipherment=true\npolicyset.serverCertSet.6.constraint.params.keyUsageKeyAgreement=false\npolicyset.serverCertSet.6.constraint.params.keyUsageKeyCertSign=false\npolicyset.serverCertSet.6.constraint.params.keyUsageCrlSign=false\npolicyset.serverCertSet.6.constraint.params.keyUsageEncipherOnly=false\npolicyset.serverCertSet.6.constraint.params.keyUsageDecipherOnly=false\npolicyset.serverCertSet.6.default.class_id=keyUsageExtDefaultImpl\npolicyset.serverCertSet.6.default.name=Key Usage Default\npolicyset.serverCertSet.6.default.params.keyUsageCritical=true\npolicyset.serverCertSet.6.default.params.keyUsageDigitalSignature=true\npolicyset.serverCertSet.6.default.params.keyUsageNonRepudiation=true\npolicyset.serverCertSet.6.default.params.keyUsageDataEncipherment=true\npolicyset.serverCertSet.6.default.params.keyUsageKeyEncipherment=true\npolicyset.serverCertSet.6.default.params.keyUsageKeyAgreement=false\npolicyset.serverCertSet.6.default.params.keyUsageKeyCertSign=false\npolicyset.serverCertSet.6.default.params.keyUsageCrlSign=false\npolicyset.serverCertSet.6.default.params.keyUsageEncipherOnly=false\npolicyset.serverCertSet.6.default.params.keyUsageDecipherOnly=false\npolicyset.serverCertSet.7.constraint.class_id=noConstraintImpl\npolicyset.serverCertSet.7.constraint.name=No Constraint\npolicyset.serverCertSet.7.default.class_id=extendedKeyUsageExtDefaultImpl\npolicyset.serverCertSet.7.default.name=Extended Key Usage Extension Default\npolicyset.serverCertSet.7.default.params.exKeyUsageCritical=false\npolicyset.serverCertSet.7.default.params.exKeyUsageOIDs=1.3.6.1.5.5.7.3.1,1.3.6.1.5.5.7.3.2\npolicyset.serverCertSet.8.constraint.class_id=signingAlgConstraintImpl\npolicyset.serverCertSet.8.constraint.name=No Constraint\npolicyset.serverCertSet.8.constraint.params.signingAlgsAllowed=SHA1withRSA,SHA256withRSA,SHA512withRSA,MD5withRSA,MD2withRSA,SHA1withDSA,SHA1withEC,SHA256withEC,SHA384withEC,SHA512withEC\npolicyset.serverCertSet.8.default.class_id=signingAlgDefaultImpl\npolicyset.serverCertSet.8.default.name=Signing Alg\npolicyset.serverCertSet.8.default.params.signingAlg=-\npolicyset.serverCertSet.9.constraint.class_id=noConstraintImpl\npolicyset.serverCertSet.9.constraint.name=No Constraint\npolicyset.serverCertSet.9.default.class_id=crlDistributionPointsExtDefaultImpl\npolicyset.serverCertSet.9.default.name=CRL Distribution Points Extension Default\npolicyset.serverCertSet.9.default.params.crlDistPointsCritical=false\npolicyset.serverCertSet.9.default.params.crlDistPointsNum=1\npolicyset.serverCertSet.9.default.params.crlDistPointsEnable_0=true\npolicyset.serverCertSet.9.default.params.crlDistPointsIssuerName_0=CN=Certificate Authority,o=ipaca\npolicyset.serverCertSet.9.default.params.crlDistPointsIssuerType_0=DirectoryName\npolicyset.serverCertSet.9.default.params.crlDistPointsPointName_0=http://ipa-ca.testrelm.test/ipa/crl/MasterCRL.bin\npolicyset.serverCertSet.9.default.params.crlDistPointsPointType_0=URIName\npolicyset.serverCertSet.9.default.params.crlDistPointsReasons_0=\npolicyset.serverCertSet.10.constraint.class_id=noConstraintImpl\npolicyset.serverCertSet.10.constraint.name=No Constraint\npolicyset.serverCertSet.10.default.class_id=subjectKeyIdentifierExtDefaultImpl\npolicyset.serverCertSet.10.default.name=Subject Key Identifier Extension Default\npolicyset.serverCertSet.10.default.params.critical=false\npolicyset.serverCertSet.11.constraint.class_id=noConstraintImpl\npolicyset.serverCertSet.11.constraint.name=No Constraint\npolicyset.serverCertSet.11.default.class_id=userExtensionDefaultImpl\npolicyset.serverCertSet.11.default.name=User Supplied Extension Default\npolicyset.serverCertSet.11.default.params.userExtOID=2.5.29.17\n'
2015-08-27T08:50:19Z DEBUG NSSConnection init cloud-qe-9.idmqe.lab.eng.bos.redhat.com
2015-08-27T08:50:19Z DEBUG Connecting: 10.16.96.106:0
2015-08-27T08:50:19Z DEBUG auth_certificate_callback: check_sig=True is_server=False
[...]
2015-08-27T08:50:19Z DEBUG approved_usage = SSL Server intended_usage = SSL Server
2015-08-27T08:50:19Z DEBUG cert valid True for "CN=cloud-qe-9.idmqe.lab.eng.bos.redhat.com,O=TESTRELM.TEST"
2015-08-27T08:50:19Z DEBUG handshake complete, peer = 10.16.96.106:8443
2015-08-27T08:50:19Z DEBUG Protocol: TLS1.2
2015-08-27T08:50:19Z DEBUG Cipher: TLS_RSA_WITH_AES_128_GCM_SHA256
2015-08-27T08:50:19Z DEBUG request status 400
2015-08-27T08:50:19Z DEBUG request reason_phrase u'Bad Request'
2015-08-27T08:50:19Z DEBUG request headers {'transfer-encoding': 'chunked', 'date': 'Thu, 27 Aug 2015 08:50:19 GMT', 'connection': 'close', 'content-type': 'application/json', 'server': 'Apache-Coyote/1.1'}
2015-08-27T08:50:19Z DEBUG request body '{"Attributes":{"Attribute":[]},"ClassName":"com.netscape.certsrv.base.BadRequestException","Code":400,"Message":"Profile already exists"}'

During normal course of installation, we shouldn't be producing 4xx and 5xx statuses.

Comment 2 Petr Vobornik 2015-08-27 10:40:39 UTC
IIUC it tries to add a certificate profile which is already there. Fraser, is it expected behavior?

Comment 3 Fraser Tweedale 2015-08-28 00:56:52 UTC
This is expected behaviour.

The installation procedure attempts to add
predefined profiles.  In the case of the "caIPAserviceCert"
profile, this is already defined by Dogtag.  The IPA code
first attempts to add the profile (which fails in this case)
and if it already exists, it updates it instead.

There was a related bug for IPA to own its own profiles,
rather than Dogtag: https://bugzilla.redhat.com/show_bug.cgi?id=916289
In a future release we can remove caIPAserviceCert from Dogtag
at which point this error will no longer occur.

Arguably the status code should be 409 Conflict but if so that
ticket should be raised against pki.

Comment 4 Petr Vobornik 2015-08-28 07:58:40 UTC
Moving to pki to evaluate the change of status code as mentioned in comment 3. Otherwise I would close as not a bug.

Comment 5 Jan Pazdziora 2015-08-28 08:13:24 UTC
(In reply to Fraser Tweedale from comment #3)
> This is expected behaviour.
> 
> The installation procedure attempts to add
> predefined profiles.  In the case of the "caIPAserviceCert"
> profile, this is already defined by Dogtag.  The IPA code
> first attempts to add the profile (which fails in this case)
> and if it already exists, it updates it instead.

Why doesn't IPA installer code check if the profile exists, before attempting to create it?

Comment 8 Matthew Harmsen 2016-01-07 17:14:35 UTC
Upstream ticket:
https://fedorahosted.org/pki/ticket/1728

Comment 9 Matthew Harmsen 2016-04-15 21:29:09 UTC
ftweedal fixed in master:
* 27a38daf9840e4fd9bc031daf25024806d05e943

Comment 11 Roshni 2016-09-02 17:22:18 UTC
[root@nightcrawler ~]# rpm -qi pki-ca
Name        : pki-ca
Version     : 10.3.3
Release     : 8.el7
Architecture: noarch
Install Date: Wed 31 Aug 2016 03:15:38 PM EDT
Group       : System Environment/Daemons
Size        : 2430595
License     : GPLv2
Signature   : (none)
Source RPM  : pki-core-10.3.3-8.el7.src.rpm
Build Date  : Tue 30 Aug 2016 03:23:27 PM EDT
Build Host  : ppc-015.build.eng.bos.redhat.com
Relocations : (not relocatable)
Packager    : Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>
Vendor      : Red Hat, Inc.
URL         : http://pki.fedoraproject.org/
Summary     : Certificate System - Certificate Authority


ipa-server-install

/var/log/pki/pki-tomcat/localhost_access_log.2016-09-02.txt has the following (no error message for the caIPAserviceCert profile)


10.16.96.83 - ipara [02/Sep/2016:12:55:33 -0400] "POST /ca/rest/profiles/caIPAserviceCert?action=disable HTTP/1.1" 204 -
10.16.96.83 - ipara [02/Sep/2016:12:55:33 -0400] "PUT /ca/rest/profiles/caIPAserviceCert/raw HTTP/1.1" 200 7053
10.16.96.83 - ipara [02/Sep/2016:12:55:33 -0400] "POST /ca/rest/profiles/caIPAserviceCert?action=enable HTTP/1.1" 204 -
10.16.96.83 - ipara [02/Sep/2016:12:55:33 -0400] "GET /ca/rest/account/logout HTTP/1.1" 204 -
10.16.96.83 - ipara [02/Sep/2016:12:55:34 -0400] "GET /ca/rest/account/login HTTP/1.1" 200 205
10.16.96.83 - ipara [02/Sep/2016:12:55:34 -0400] "GET /ca/rest/authorities/host-authority HTTP/1.1" 200 310
10.16.96.83 - ipara [02/Sep/2016:12:55:34 -0400] "GET /ca/rest/account/logout HTTP/1.1" 204 -


/var/log/ipaserver-install.log has the following

2016-09-02T16:55:33Z DEBUG response headers {'transfer-encoding': 'chunked', 'date': 'Fri, 02 Sep 2016 16:55:32 GMT', 'content-type': 'application/json', 'server': 'Apache-Coyote/1.1'}
2016-09-02T16:55:33Z DEBUG response body '{"Attributes":{"Attribute":[]},"ClassName":"com.netscape.certsrv.base.ConflictingOperationException","Code":409,"Message":"Profile already exists"}'
2016-09-02T16:55:33Z DEBUG Error migrating 'caIPAserviceCert': Non-2xx response from CA REST API: 409. Profile already exists

Fraser,

Please confirm if the above are the expected log messages.

Comment 12 Fraser Tweedale 2016-09-04 07:31:30 UTC
Roshni, this is the expected behaviour.

Comment 14 errata-xmlrpc 2016-11-04 05:19:40 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHBA-2016-2396.html


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