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/profileSu...' 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@6a6078e7, profileContext=com.netscape.cms.profile.common.EnrollProfileContext@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/profileSubm...'
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@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@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@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@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/profileSubm...' [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)