[Pki-devel] Auth failure setting up the mod Proxy ajp
Adam Young
ayoung at redhat.com
Thu Aug 18 03:11:53 UTC 2011
I've made the same changes as I did last night, modulo that I've
attempted to modify the IPA files in the repo and deploy them to the IPA
server. However, when I attempt to talk to the server I get the
following error. I suspect that I have mod_auth_proxy using the wrong
port, based on the message at the top.
THese are the ports I'm using
+ ('ca_port', 80),
+ ('ca_agent_port', 443),
+ ('ca_ee_port', 443),
I'm using the dogtag.conf file you posted last night, which has
everything going to
ProxyPassMatch ajp://127.0.0.1:8009/
ProxyPassReverse ajp://127.0.0.1:8009/
server.xml has
<Connector port="8009" protocol="AJP/1.3" redirectPort="9444" />
All filters are disabled in web.xml
Restarted server ( a couple times). I've tried enabling basic auth
instead of using Kerberos, but that seems to make no difference,
although it does make me wonder about how we are going to pass
authentication through in the future.
here's the error from the debug log
[17/Aug/2011:22:56:33][TP-Processor8]:
com.netscape.cms.servlet.filter.EERequestFilter: Use HTTPS port '9444'
instead of '443' when performing EE tasks!
[17/Aug/2011:22:56:33][TP-Processor8]: Filter is disabled .. continuing
[17/Aug/2011:22:56:33][TP-Processor8]: CMSServlet:service() uri =
//ca/ee/ca/profileSubmitSSLClient
[17/Aug/2011:22:56:33][TP-Processor8]: CMSServlet::service() param
name='cert_request_type' value='pkcs10'
[17/Aug/2011:22:56:33][TP-Processor8]: CMSServlet::service() param
name='cert_request' value='-----BEGIN CERTIFICATE REQUEST-----
MIIBbzCB2QIBADAwMS4wLAYDVQQDEyVncmFtcGEuYXlvdW5nLmJvc3Rvbi5kZXZl
bC5yZWRoYXQuY29tMIGfMA0GCSqGSIb3DQEBAQUAA4GNADCBiQKBgQC1+Igq1HNT
V2Q35EBq8RoDTQxu+Hfquv8jDyLqlvw6O5sDnIldR0JnvJjZBYZS2TFyi2U1hXxJ
zSg3xhM/7UF9TVerC7HIqRtXo1EPrzxfQZwOWOsZewtQc/cPCkLP4gz9rFXVtBwq
z363YoKJIuXpNTeQyqAvYHTyeRvAth+xswIDAQABoAAwDQYJKoZIhvcNAQEFBQAD
gYEARnikLtPQIAkfjDR5P/nNsTNjwMeGTxizPrt0e5uKaOTL+gsV747bYdRKL96G
11RPEtD1VwvuHbS4ao43oJ4gqOMsxWSXM4h1QcMF0Qz30G6ddobFTWh0XfRL32Dh
4cOxVGMp2IocJvi9VutQVZkwv7NO2GQ52yvZWgzNDdRKujY=
-----END CERTIFICATE REQUEST-----'
[17/Aug/2011:22:56:33][TP-Processor8]: CMSServlet::service() param
name='xml' value='true'
[17/Aug/2011:22:56:33][TP-Processor8]: CMSServlet::service() param
name='profileId' value='caIPAserviceCert'
[17/Aug/2011:22:56:33][TP-Processor8]: CMSServlet:
caProfileSubmitSSLClient start to service.
[17/Aug/2011:22:56:33][TP-Processor8]: xmlOutput true
[17/Aug/2011:22:56:33][TP-Processor8]: Start of ProfileSubmitServlet
Input Parameters
[17/Aug/2011:22:56:33][TP-Processor8]: ProfileSubmitServlet Input
Parameter cert_request_type='pkcs10'
[17/Aug/2011:22:56:33][TP-Processor8]: ProfileSubmitServlet Input
Parameter cert_request='-----BEGIN CERTIFICATE REQUEST-----
MIIBbzCB2QIBADAwMS4wLAYDVQQDEyVncmFtcGEuYXlvdW5nLmJvc3Rvbi5kZXZl
bC5yZWRoYXQuY29tMIGfMA0GCSqGSIb3DQEBAQUAA4GNADCBiQKBgQC1+Igq1HNT
V2Q35EBq8RoDTQxu+Hfquv8jDyLqlvw6O5sDnIldR0JnvJjZBYZS2TFyi2U1hXxJ
zSg3xhM/7UF9TVerC7HIqRtXo1EPrzxfQZwOWOsZewtQc/cPCkLP4gz9rFXVtBwq
z363YoKJIuXpNTeQyqAvYHTyeRvAth+xswIDAQABoAAwDQYJKoZIhvcNAQEFBQAD
gYEARnikLtPQIAkfjDR5P/nNsTNjwMeGTxizPrt0e5uKaOTL+gsV747bYdRKL96G
11RPEtD1VwvuHbS4ao43oJ4gqOMsxWSXM4h1QcMF0Qz30G6ddobFTWh0XfRL32Dh
4cOxVGMp2IocJvi9VutQVZkwv7NO2GQ52yvZWgzNDdRKujY=
-----END CERTIFICATE REQUEST-----'
[17/Aug/2011:22:56:33][TP-Processor8]: ProfileSubmitServlet Input
Parameter xml='true'
[17/Aug/2011:22:56:33][TP-Processor8]: ProfileSubmitServlet Input
Parameter profileId='caIPAserviceCert'
[17/Aug/2011:22:56:33][TP-Processor8]: End of ProfileSubmitServlet Input
Parameters
[17/Aug/2011:22:56:33][TP-Processor8]: ProfileSubmitServlet: start serving
[17/Aug/2011:22:56:33][TP-Processor8]: ProfileSubmitServlet: SubId=profile
[17/Aug/2011:22:56:33][TP-Processor8]: ProfileSubmitServlet: isRenewal false
[17/Aug/2011:22:56:33][TP-Processor8]: ProfileSubmitServlet: profileId
caIPAserviceCert
[17/Aug/2011:22:56:33][TP-Processor8]: ProfileSubmitServlet:
authenticator raCertAuth found
[17/Aug/2011:22:56:33][TP-Processor8]:
ProfileSubmitServlet:setCredentialsIntoContext() authIds` null
[17/Aug/2011:22:56:33][TP-Processor8]: ProfileSubmistServlet: set Inputs
into profile Context
[17/Aug/2011:22:56:33][TP-Processor8]: ProfileSubmitServlet: set
sslClientCertProvider
[17/Aug/2011:22:56:33][TP-Processor8]: ProfileSubmitServlet:
authentication required.
[17/Aug/2011:22:56:33][TP-Processor8]: CMSServlet: in auditSubjectID
[17/Aug/2011:22:56:33][TP-Processor8]: CMSServlet: auditSubjectID
auditContext
{sslClientCertProvider=com.netscape.cms.servlet.profile.SSLClientCertProvider at 6a6078e7,
profileContext=com.netscape.cms.profile.common.EnrollProfileContext at 63a1bc40}
[17/Aug/2011:22:56:33][TP-Processor8]: CMSServlet auditSubjectID:
subjectID: null
[17/Aug/2011:22:56:33][TP-Processor8]: AgentCertAuthentication: start
[17/Aug/2011:22:56:33][TP-Processor8]: authenticator instance name is
raCertAuth
[17/Aug/2011:22:56:33][TP-Processor8]: AgentCertAuthenticator: got provider
[17/Aug/2011:22:56:33][TP-Processor8]: AgentCertAuthenticator:
retrieving client certificate
[17/Aug/2011:22:56:33][TP-Processor8]: AgentCertAuthentication: No SSL
Client Certs Found
[17/Aug/2011:22:56:33][TP-Processor8]: ProfileSubmitServlet:
authentication error Invalid Credential.
[17/Aug/2011:22:56:33][TP-Processor8]: SignedAuditEventFactory: create()
message=[AuditEvent=AUTH_FAIL][SubjectID=$NonRoleUser$ :
Unidentified][Outcome=Failure][AuthMgr=raCertAuth][AttemptedCred=Unidentified]
authentication failure
[17/Aug/2011:22:56:33][TP-Processor8]: CMSServlet: curDate=Wed Aug 17
22:56:33 EDT 2011 id=caProfileSubmitSSLClient time=32
All the httpd log shows is:
[Wed Aug 17 23:04:49 2011] [error] ipa: INFO: sslget
'https://ipa-server-3.ayoung.boston.devel.redhat.com:443/ca/ee/ca/profileSubmitSSLClient'
If I enable debugging in NSS I get:
[Wed Aug 17 23:11:23 2011] [info] Connection to child 4 established
(server ipa-server-3.ayoung.boston.devel.redhat.com:443, client
192.168.122.203)
[Wed Aug 17 23:11:23 2011] [info] Initial (No.1) HTTPS request received
for child 4 (server ipa-server-3.ayoung.boston.devel.redhat.com:443)
[Wed Aug 17 23:11:23 2011] [debug] src/mod_auth_kerb.c(1578): [client
192.168.122.203] kerb_authenticate_user entered with user (NULL) and
auth_type Kerberos, referer:
https://ipa-server-3.ayoung.boston.devel.redhat.com/ipa/ui/
[Wed Aug 17 23:11:23 2011] [debug] src/mod_auth_kerb.c(967): [client
192.168.122.203] Using
HTTP/ipa-server-3.ayoung.boston.devel.redhat.com at IPA-SERVER-3.AYOUNG.BOSTON.DEVEL.REDHAT.COM
as server principal for password verification, referer:
https://ipa-server-3.ayoung.boston.devel.redhat.com/ipa/ui/
[Wed Aug 17 23:11:23 2011] [debug] src/mod_auth_kerb.c(671): [client
192.168.122.203] Trying to get TGT for user
admin at IPA-SERVER-3.AYOUNG.BOSTON.DEVEL.REDHAT.COM, referer:
https://ipa-server-3.ayoung.boston.devel.redhat.com/ipa/ui/
[Wed Aug 17 23:11:24 2011] [debug] src/mod_auth_kerb.c(581): [client
192.168.122.203] Trying to verify authenticity of KDC using principal
HTTP/ipa-server-3.ayoung.boston.devel.redhat.com at IPA-SERVER-3.AYOUNG.BOSTON.DEVEL.REDHAT.COM,
referer: https://ipa-server-3.ayoung.boston.devel.redhat.com/ipa/ui/
[Wed Aug 17 23:11:24 2011] [debug] src/mod_auth_kerb.c(1046): [client
192.168.122.203] kerb_authenticate_user_krb5pwd ret=0
user=admin at IPA-SERVER-3.AYOUNG.BOSTON.DEVEL.REDHAT.COM authtype=Basic,
referer: https://ipa-server-3.ayoung.boston.devel.redhat.com/ipa/ui/
[Wed Aug 17 23:11:25 2011] [error] ipa: INFO: sslget
'https://ipa-server-3.ayoung.boston.devel.redhat.com:443/ca/ee/ca/profileSubmitSSLClient'
[Wed Aug 17 23:11:25 2011] [info] Connection to child 6 established
(server ipa-server-3.ayoung.boston.devel.redhat.com:443, client
192.168.122.203)
[Wed Aug 17 23:11:25 2011] [info] Initial (No.1) HTTPS request received
for child 6 (server ipa-server-3.ayoung.boston.devel.redhat.com:443)
[Wed Aug 17 23:11:25 2011] [debug] mod_proxy_ajp.c(45): proxy: AJP:
canonicalising URL //127.0.0.1:8009//ca/ee/ca/profileSubmitSSLClient
[Wed Aug 17 23:11:25 2011] [debug] proxy_util.c(1506): [client
192.168.122.203] proxy: ajp: found worker ajp://127.0.0.1:8009/ for
ajp://127.0.0.1:8009//ca/ee/ca/profileSubmitSSLClient
[Wed Aug 17 23:11:25 2011] [debug] mod_proxy.c(1015): Running scheme ajp
handler (attempt 0)
[Wed Aug 17 23:11:25 2011] [debug] mod_proxy_http.c(1963): proxy: HTTP:
declining URL ajp://127.0.0.1:8009//ca/ee/ca/profileSubmitSSLClient
[Wed Aug 17 23:11:25 2011] [debug] mod_proxy_ajp.c(659): proxy: AJP:
serving URL ajp://127.0.0.1:8009//ca/ee/ca/profileSubmitSSLClient
[Wed Aug 17 23:11:25 2011] [debug] proxy_util.c(2011): proxy: AJP: has
acquired connection for (127.0.0.1)
[Wed Aug 17 23:11:25 2011] [debug] proxy_util.c(2067): proxy: connecting
ajp://127.0.0.1:8009//ca/ee/ca/profileSubmitSSLClient to 127.0.0.1:8009
[Wed Aug 17 23:11:25 2011] [debug] proxy_util.c(2193): proxy: connected
//ca/ee/ca/profileSubmitSSLClient to 127.0.0.1:8009
[Wed Aug 17 23:11:25 2011] [debug] proxy_util.c(2444): proxy: AJP: fam 2
socket created to connect to 127.0.0.1
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(224): Into
ajp_marshal_into_msgb
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(290):
ajp_marshal_into_msgb: Header[0] [Host] =
[ipa-server-3.ayoung.boston.devel.redhat.com]
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(290):
ajp_marshal_into_msgb: Header[1] [Accept-Encoding] = [identity]
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(290):
ajp_marshal_into_msgb: Header[2] [Content-Length] = [681]
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(290):
ajp_marshal_into_msgb: Header[3] [Content-type] =
[application/x-www-form-urlencoded]
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(290):
ajp_marshal_into_msgb: Header[4] [Accept] = [text/plain]
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(450):
ajp_marshal_into_msgb: Done
[Wed Aug 17 23:11:25 2011] [debug] mod_proxy_ajp.c(265): proxy:
APR_BUCKET_IS_EOS
[Wed Aug 17 23:11:25 2011] [debug] mod_proxy_ajp.c(270): proxy: data to
read (max 8186 at 4)
[Wed Aug 17 23:11:25 2011] [debug] mod_proxy_ajp.c(285): proxy: got 681
bytes of data
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(687): ajp_read_header:
ajp_ilink_received 04
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(697): ajp_parse_type: got 04
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(516):
ajp_unmarshal_response: status = 200
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(537):
ajp_unmarshal_response: Number of headers is = 2
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(599):
ajp_unmarshal_response: Header[0] [Content-Type] = [application/xml]
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(609):
ajp_unmarshal_response: ap_set_content_type done
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(599):
ajp_unmarshal_response: Header[1] [Content-Length] = [134]
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(687): ajp_read_header:
ajp_ilink_received 03
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Aug 17 23:11:25 2011] [info] Connection to child 4 closed (server
ipa-server-3.ayoung.boston.devel.redhat.com:443, client 192.168.122.203)
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(687): ajp_read_header:
ajp_ilink_received 05
[Wed Aug 17 23:11:25 2011] [debug] ajp_header.c(697): ajp_parse_type: got 05
[Wed Aug 17 23:11:25 2011] [debug] mod_proxy_ajp.c(568): proxy: got
response from (null) (127.0.0.1)
[Wed Aug 17 23:11:25 2011] [debug] proxy_util.c(2029): proxy: AJP: has
released connection for (127.0.0.1)
[Wed Aug 17 23:11:25 2011] [info] Connection to child 6 closed (server
ipa-server-3.ayoung.boston.devel.redhat.com:443, client 192.168.122.203)
More information about the Pki-devel
mailing list