[Pki-devel] Auth failure setting up the mod Proxy ajp
Ade Lee
alee at redhat.com
Thu Aug 18 13:44:27 UTC 2011
Hmm, this is unfortunate. I was hoping that this would work.
The port you are using is fine. The first two lines of the debug log
indicate that the filters (which enforce that certain requests go
through certain ports) would have stopped this interaction right here -
had they not been disabled.
Whats happening is the following:
Typically, a user submits a certificate request after selecting a
profile on the end-entity pages. The EE pages are reached through the
non-client-auth SSL port. There are however, some profiles that require
a certificate for authentication. In this case, for example, we expect
the request to be accompanied by an agent's certificate so that the
certificate request is automatically processed.
At this point - and I'm fuzzy about exactly how - we initiate a
renegotiation of the connection and require a client certificate.
When talking to tomcat directly - this happens through tomcatjss/jss.
In this case, when going through the proxy - it appears the
renegotiation is not taking place - and no client cert is being sent.
I have a couple of ideas on how to get around this:
1. It may just be a httpd configuration issue. Change the dogtag.conf
file so that all stanzas contain the following line:
NSSOptions +StdEnvVars +ExportCertData +StrictRequire +OptRenegotiate
rather than just the agent one. Hopefully, this will just work.
2. When I was trying to address the MITM issues, I ended up adding a
client-auth EE port - so that renegotiations would not take place (to
help non-updated clients).
You can get to that port by changing the URL to ..
'https://ipa-server-3.ayoung.boston.devel.redhat.com:443/ca/eeca/ca/profileSubmitSSLClient'
Note: eeca instead of ee.
Ade
On Wed, 2011-08-17 at 23:11 -0400, Adam Young wrote:
> 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