I have a machine set up that only has IPv6 set as a DNS resolvable IPAddress. The install failed at this point:
2011-06-17 20:43:34,809 DEBUG approved_usage = SSLServer intended_usage = SSLServer 2011-06-17 20:43:34,809 DEBUG cert valid True for "CN=netbook.home.younglogic.com,O=NETBOOK.HOME.YOUNGLOGIC.COM" 2011-06-17 20:43:34,856 DEBUG handshake complete, peer = [2002:1822:6d5f:0:223:54ff:fe12:1ed]:9444 2011-06-17 20:43:35,027 DEBUG Certificate issuance failed
2011-06-17 20:43:35,027 DEBUG Certificate issuance failed File "/usr/sbin/ipa-server-install", line 983, in <module> sys.exit(main())
File "/usr/sbin/ipa-server-install", line 825, in main hbac_allow=not options.hbac_allow)
File "/usr/lib/python2.7/site-packages/ipaserver/install/dsinstance.py", line 263, in create_instance self.start_creation("Configuring directory server", 60)
File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 289, in start_creation method()
File "/usr/lib/python2.7/site-packages/ipaserver/install/dsinstance.py", line 529, in __enable_ssl self.dercert = dsdb.create_server_cert("Server-Cert", self.fqdn, cadb)
File "/usr/lib/python2.7/site-packages/ipaserver/install/certs.py", line 511, in create_server_cert cdb.issue_server_cert(self.certreq_fname, self.certder_fname)
File "/usr/lib/python2.7/site-packages/ipaserver/install/certs.py", line 615, in issue_server_cert raise RuntimeError("Certificate issuance failed")
The Dogtag Catalina log has this in it:
INFO: Deploying web application directory ROOT Jun 17, 2011 8:41:03 PM org.apache.catalina.startup.HostConfig deployDirectory INFO: Deploying web application directory ca Jun 17, 2011 8:41:04 PM org.apache.catalina.startup.Catalina stopServer SEVERE: Catalina.stop: java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384) at java.net.Socket.connect(Socket.java:546) at java.net.Socket.connect(Socket.java:495) at java.net.Socket.<init>(Socket.java:392) at java.net.Socket.<init>(Socket.java:206) at org.apache.catalina.startup.Catalina.stopServer(Catalina.java:412) 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:616) at org.apache.catalina.startup.Bootstrap.stopServer(Bootstrap.java:338) at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:416) 32-bit osutil library loaded 32-bit osutil library loaded Server is started.
This was in /var/log/pki-ca/localhost.2011-06-17.log
INFO: Use of the properties initialization parameter 'properties' has been deprecated by 'org.apache.velocity.properties' Jun 17, 2011 8:40:24 PM org.apache.catalina.core.ApplicationContext log SEVERE: Servlet castart threw unload() exception javax.servlet.ServletException: Servlet.destroy() for servlet castart threw exception at org.apache.catalina.core.StandardWrapper.unload(StandardWrapper.java:1413) at org.apache.catalina.core.StandardWrapper.stop(StandardWrapper.java:1739) at org.apache.catalina.core.StandardContext.stop(StandardContext.java:4832) at org.apache.catalina.core.ContainerBase.removeChild(ContainerBase.java:932) at org.apache.catalina.startup.HostConfig.undeployApps(HostConfig.java:1319) at org.apache.catalina.startup.HostConfig.stop(HostConfig.java:1290) at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:323) at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:142) at org.apache.catalina.core.ContainerBase.stop(ContainerBase.java:1094) at org.apache.catalina.core.ContainerBase.stop(ContainerBase.java:1106) at org.apache.catalina.core.StandardEngine.stop(StandardEngine.java:468) at org.apache.catalina.core.StandardService.stop(StandardService.java:604) at org.apache.catalina.core.StandardServer.stop(StandardServer.java:735) at org.apache.catalina.startup.Catalina.stop(Catalina.java:652) at org.apache.catalina.startup.Catalina.start(Catalina.java:619) 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:616) at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289) at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414) Caused by: java.lang.NullPointerException at com.netscape.ca.CertificateAuthority.shutdown(CertificateAuthority.java:496) at com.netscape.cmscore.apps.CMSEngine.shutdownSubsystems(CMSEngine.java:1587) at com.netscape.cmscore.apps.CMSEngine.shutdown(CMSEngine.java:1530) at com.netscape.certsrv.apps.CMS.shutdown(CMS.java:199) at com.netscape.cms.servlet.base.CMSStartServlet.destroy(CMSStartServlet.java:108) at org.apache.catalina.core.StandardWrapper.unload(StandardWrapper.java:1394) ... 20 more
attachment ipaserver-install.log
I did a quick test and I can telnet to 2002:1822:6d5f:0:223:54ff:fe12:1ed 9444 so the port is open and something is listening
I was able to duplicate this on an IPv6-only install. We aren't sending the RA client cert which is why the request is failing. Why we aren't sending the cert is quite unclear. I stuck a pdb.set_trace() in the client cert callback and it never broke there. The IPv6 request otherwise seems to work ok.
I did tests with dogtag's sslget utility and that worked fine.
The problem is related to our fallback from IPv4 to IPv6. By default the NSS connection tries IPv4 and falls back to v6, something must be dropped in this fallback.
You have to create a new socket for each address returned by get_addr_info(), not sure if we're doing that or not.
Also, I'm not sure we're using get_addr_info() correctly. Last I looked at the code it looked like it was trying to force an IPv4 family. You're supposed to just give an an address and let it return you an ordered list of potential address to iterate over, trying each until one succeeds. I think the reason the code was added in the form it is now is because it was copied from an example test program which let you force a family for testing purposes. That logic is not generally appropriate.
Even if we do the addr info properly there is a problem that if we call set_client_auth_data_callback() before connect() there is now way in nsslib for it to know that it was called or what the callback function is, so if it has to fall back to another family type for whatever reason that callback will be lost.
It looks like we can move the callback past the connect() and that seems to fix things.
The callbacks are bound to the socket object, in other words you set them on the socket. They are not "global". I believe the right place to set them is just after you create the socket object.
I'm afraid if you set the callback after connect() it won't be invoked during the SSL handshake performed during the connect. Make sense?
attachment freeipa-rcrit-811-dogtag.patch
I tested this patch on an IPv4 and an IPv6 system and it worked in both cases. The IPv6 server does a fallback, the IPv4 does not, and both successfully install.
fixed in 6ad7deb
Metadata Update from @admiyo: - Issue assigned to rcritten - Issue set to the milestone: FreeIPA 2.1 - 2011/07
Login to comment on this ticket.