Created attachment 581554 [details]
stdout from install

stdout

Created attachment 581556 [details]
ipaserver-install.log

ipaserver-install.log from install

I can also confirm the issue described in Description.

I tried with the latest stable version on F16 
=============================
[root@regular-guest ~]# rpm -q freeipa-server ; cat /etc/fedora-release 
freeipa-2.1.4-7.fc16
Fedora release 16 (Verne)
[root@regular-guest ~]#
=============================

and with development repo:
=============================
[root@regular-guest ~]# rpm -q freeipa-server pki-silent pki-ca 389-ds-base
freeipa-server-2.1.90.rc1-0.fc16.x86_64
pki-silent-9.0.19-1.fc16.noarch
pki-ca-9.0.19-1.fc16.noarch
389-ds-base-1.2.10.6-1.fc16.x86_64

=============================

with the developemnt repo, running the ipa-server-install 


==============
 ipa-server-install --setup-dns --forwarder=10.x.y.z -r FOO.BAR.COM -p testpwd -P testpwd -a testpwd -U
.
.
.
Configuring directory server for the CA: Estimated time 30 seconds
  [1/3]: creating directory server user
  [2/3]: creating directory server instance
ipa         : CRITICAL failed to restart ds instance Command '/usr/sbin/setup-ds.pl --silent --logfile - -f /tmp/tmpElBwGd' returned non-zero exit status 1
  [3/3]: restarting directory server
ipa         : CRITICAL Failed to restart the directory server. See the installation log for details.
==============

Kashyap, the error with 2.1.90 is unrelated and would need a separate BZ (389-ds is failing to start, not the CA).

The problem is that the CA is not starting. Please attatch the logs for the CA found in /var/log/pki-ca and /var/log/pki-ca-install.log.

Upstream ticket:
https://fedorahosted.org/freeipa/ticket/2711

It looks like there are two issues here:

1. CA not starting.  We would need to see logs under /var/log/pki-ca (pariticularly the catalina.out log) as well as any selinux messages (/var/log/messages and /var/log/audit/audit/log)

2. ConfigureCA class not found for pkisilent.  This is a IPA script issue that is supposed to be fixed.  Rob?

Created attachment 581710 [details]
pki-ca-install.log

pki-ca-install.log from failed install

Created attachment 581711 [details]
messages log file

Created attachment 581712 [details]
audit.log

(In reply to comment #6)
> It looks like there are two issues here:
> 
> 1. CA not starting.  We would need to see logs under /var/log/pki-ca
> (pariticularly the catalina.out log) as well as any selinux messages
> (/var/log/messages and /var/log/audit/audit/log)
> 
> 2. ConfigureCA class not found for pkisilent.  This is a IPA script issue that
> is supposed to be fixed.  Rob?

I have attached the logs you asked for, catalina.log was empty.

What version of freeipa-server is this? If it isn't freeipa-2.1.4-7.fc16 can you try updating (should be in stable now) and see if that works?

I think the problem is an incompatibility with updated dogtag bits. We were doing shell escape of arguments passed to pkisilent and they started handling this themselves. If both did it then dogtag would blow up.

(In reply to comment #11)
> What version of freeipa-server is this? If it isn't freeipa-2.1.4-7.fc16 can
> you try updating (should be in stable now) and see if that works?
> 
> I think the problem is an incompatibility with updated dogtag bits. We were
> doing shell escape of arguments passed to pkisilent and they started handling
> this themselves. If both did it then dogtag would blow up.

I believe this is latest version...

[root@zion anders]# rpm -q freeipa-server
freeipa-server-2.1.4-7.fc16.x86_64

Ok, this means you have the shell fix which was Ade's concern 2 in c#10.

Created attachment 582511 [details]
f17-ipaserver-install.log

Created attachment 582512 [details]
f17-pki-ca-install.log

Just verified, that the bug is also available on fully updated f17 branch system.

(In reply to comment #14)
> Created attachment 582511 [details]
> f17-ipaserver-install.log

This is a different failure:

Error in LdapConnectionPanel(): updateStatus returns failure
ERROR: ConfigureCA: LdapConnectionPanel() failure
ERROR: unable to create CA

In this case the CA was installed and started but apparently couldn't talk to its own LDAP server. Can you see if there are any AVCs? Can you attach /var/log/pki-ca/debug?

(In reply to comment #17)
> (In reply to comment #14)
> > Created attachment 582511 [details]
> > f17-ipaserver-install.log
> 
> This is a different failure:
> 
> Error in LdapConnectionPanel(): updateStatus returns failure
> ERROR: ConfigureCA: LdapConnectionPanel() failure
> ERROR: unable to create CA
> 
> In this case the CA was installed and started but apparently couldn't talk to
> its own LDAP server. Can you see if there are any AVCs? Can you attach
> /var/log/pki-ca/debug?

I could not find /var/log/pki-ca/debug on my system.

dezent, you do not have this file because the CA is not starting at all. This is different than Thorsten is seeing.

In your case, and I'm not sure why I didn't see this initially, is this in /var/log/messages:

May  2 22:09:00 zion pkicontrol[1717]: /usr/bin/runcon: invalid context: system_u:system_r:pki_ca_script_t:s0: Invalid argument
May  2 22:09:00 zion systemd[1]: pki-cad: control process exited, code=exited status=1
May  2 22:09:00 zion systemd[1]: Unit pki-cad entered failed state.

What is the package version of pki-ca, pki-silent, pki-setup and freeipa-server?

(In reply to comment #19)
> dezent, you do not have this file because the CA is not starting at all. This
> is different than Thorsten is seeing.
> 
> In your case, and I'm not sure why I didn't see this initially, is this in
> /var/log/messages:
> 
> May  2 22:09:00 zion pkicontrol[1717]: /usr/bin/runcon: invalid context:
> system_u:system_r:pki_ca_script_t:s0: Invalid argument
> May  2 22:09:00 zion systemd[1]: pki-cad: control process
> exited, code=exited status=1
> May  2 22:09:00 zion systemd[1]: Unit pki-cad entered failed
> state.
> 
> What is the package version of pki-ca, pki-silent, pki-setup and
> freeipa-server?

Sorry about that, i did not read properly.. was sitting on the train.

my versions are
pki-ca-9.0.19-1
pki-silent-9.0.19-1
pki-setup-9.0.19-1
freeipa-server-2.1.4-7

i am not sure, but i think i enabled testing repo and tried to do an upgrade
a couple of days ago.

dezent, try: yum re-install pki-selinux

Then ipa-server-install --uninstall && ipa-server-install ...

Created attachment 583814 [details]
/var/log/pki-ca/debug

(In reply to comment #17)
> (In reply to comment #14)
> > Created attachment 582511 [details]
> > f17-ipaserver-install.log
> 
> This is a different failure:
> 
> Error in LdapConnectionPanel(): updateStatus returns failure
> ERROR: ConfigureCA: LdapConnectionPanel() failure
> ERROR: unable to create CA
> 
> In this case the CA was installed and started but apparently couldn't talk to
> its own LDAP server. Can you see if there are any AVCs? Can you attach
> /var/log/pki-ca/debug?

Log is attached.

Note: When I do a yum install(after yum clean all) I get from the freeipa devel repo -- freeipa-server-2.1.90.rc1-0.fc16.x86_64  (Last change made in Mar2012 -- from changelog)

But, in the devel repo [1]

I notice this version -- freeipa-server-2.1.4-1.20120209T0216Zgit11c25a4.fc16.x86_64.rpm  (which is significantly older from the changelog. Last change made in OCT2011 -- from changelog)

[1] http://jdennis.fedorapeople.org/ipa-devel/fedora/16/x86_64/os/


==============================================================================
[root@regular-guest dirsrv]#ipa-server-install --setup-dns --no-forwarders -r ENGLAB.PNQ.TEST.COM -p testpwd -P testpwd -a testpwd -U

.
.
.
.
Configuring directory server for the CA: Estimated time 30 seconds
  [1/3]: creating directory server user
  [2/3]: creating directory server instance
  [3/3]: restarting directory server
done configuring pkids.
Configuring certificate server: Estimated time 3 minutes 30 seconds
  [1/16]: creating certificate server user
  [2/16]: configuring certificate server instance
ipa         : CRITICAL failed to configure ca instance Command '/usr/bin/perl /usr/bin/pkisilent 'ConfigureCA' '-cs_hostname' 'regular-guest.englab.pnq.redhat.com' '-cs_port' '9445' '-client_certdb_dir' '/tmp/tmp-t8gRZ4' '-client_certdb_pwd' XXXXXXXX '-preop_pin' 'HyE1i9gtNi3fp64ClH7K' '-domain_name' 'IPA' '-admin_user' 'admin' '-admin_email' 'root@localhost' '-admin_password' XXXXXXXX '-agent_name' 'ipa-ca-agent' '-agent_key_size' '2048' '-agent_key_type' 'rsa' '-agent_cert_subject' 'CN=ipa-ca-agent,O=ENGLAB.PNQ.TEST.COM' '-ldap_host' 'regular-guest.englab.pnq.redhat.com' '-ldap_port' '7389' '-bind_dn' 'cn=Directory Manager' '-bind_password' XXXXXXXX '-base_dn' 'o=ipaca' '-db_name' 'ipaca' '-key_size' '2048' '-key_type' 'rsa' '-key_algorithm' 'SHA256withRSA' '-save_p12' 'true' '-backup_pwd' XXXXXXXX '-subsystem_name' 'pki-cad' '-token_name' 'internal' '-ca_subsystem_cert_subject_name' 'CN=CA Subsystem,O=ENGLAB.PNQ.TEST.COM' '-ca_ocsp_cert_subject_name' 'CN=OCSP Subsystem,O=ENGLAB.PNQ.TEST.COM' '-ca_server_cert_subject_name' 'CN=regular-guest.englab.pnq.redhat.com,O=ENGLAB.PNQ.TEST.COM' '-ca_audit_signing_cert_subject_name' 'CN=CA Audit,O=ENGLAB.PNQ.TEST.COM' '-ca_sign_cert_subject_name' 'CN=Certificate Authority,O=ENGLAB.PNQ.TEST.COM' '-external' 'false' '-clone' 'false'' returned non-zero exit status 255
Unexpected error - see ipaserver-install.log for details:
 Configuration of CA failed

==============================================================================
2012-05-16T10:11:25Z DEBUG stderr=Exception in thread "main" java.lang.NoClassDefFoundError: 'ConfigureCA'
Caused by: java.lang.ClassNotFoundException: 'ConfigureCA'
        at java.net.URLClassLoader$1.run(URLClassLoader.java:217)
        at java.security.AccessController.doPrivileged(Native Method)
        at java.net.URLClassLoader.findClass(URLClassLoader.java:205)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:321)
        at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:294)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:266)
Could not find the main class: 'ConfigureCA'. Program will exit.

2012-05-16T10:11:25Z CRITICAL failed to configure ca instance Command '/usr/bin/perl /usr/bin/pkisilent 'ConfigureCA' '-cs_hostname' 'regular-guest.englab.pnq.redhat.com' '-cs_port' '9445' '-client_certdb_dir' '/tmp/tmp-MlTEZF' '-client_certdb_pwd' XXXXXXXX '-preop_pin' 'HyE1i9gtNi3fp64ClH7K' '-domain_name' 'IPA' '-admin_user' 'admin' '-admin_email' 'root@localhost' '-admin_password' XXXXXXXX '-agent_name' 'ipa-ca-agent' '-agent_key_size' '2048' '-agent_key_type' 'rsa' '-agent_cert_subject' 'CN=ipa-ca-agent,O=ENGLAB.PNQ.TEST.COM' '-ldap_host' 'regular-guest.englab.pnq.redhat.com' '-ldap_port' '7389' '-bind_dn' 'cn=Directory Manager' '-bind_password' XXXXXXXX '-base_dn' 'o=ipaca' '-db_name' 'ipaca' '-key_size' '2048' '-key_type' 'rsa' '-key_algorithm' 'SHA256withRSA' '-save_p12' 'true' '-backup_pwd' XXXXXXXX '-subsystem_name' 'pki-cad' '-token_name' 'internal' '-ca_subsystem_cert_subject_name' 'CN=CA Subsystem,O=ENGLAB.PNQ.TEST.COM' '-ca_ocsp_cert_subject_name' 'CN=OCSP Subsystem,O=ENGLAB.PNQ.TEST.COM' '-ca_server_cert_subject_name' 'CN=regular-guest.englab.pnq.redhat.com,O=ENGLAB.PNQ.TEST.COM' '-ca_audit_signing_cert_subject_name' 'CN=CA Audit,O=ENGLAB.PNQ.TEST.COM' '-ca_sign_cert_subject_name' 'CN=Certificate Authority,O=ENGLAB.PNQ.TEST.COM' '-external' 'false' '-clone' 'false'' returned non-zero exit status 255
2012-05-16T10:11:25Z DEBUG Configuration of CA failed
  File "/usr/sbin/ipa-server-install", line 1097, in <module>
    rval = main()

  File "/usr/sbin/ipa-server-install", line 888, in main
    subject_base=options.subject)

  File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py", line 531, in configure_instance
    self.start_creation("Configuring certificate server", 210)

  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 257, in start_creation
    method()

  File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py", line 670, in __configure_instance
    raise RuntimeError('Configuration of CA failed')
==============================================================================
[root@regular-guest slapd-PKI-IPA]# systemctl status dirsrv
dirsrv - 389 Directory Server PKI-IPA.
	  Loaded: loaded (/lib/systemd/system/dirsrv@.service; enabled)
	  Active: active (running) since Wed, 16 May 2012 06:16:27 -0400; 2min 30s ago
	 Process: 18512 ExecStopPost=/bin/rm -f /var/run/dirsrv/slapd-%i.pid (code=exited, status=0/SUCCESS)
	 Process: 18515 ExecStart=/usr/sbin/ns-slapd -D /etc/dirsrv/slapd-%i -i /var/run/dirsrv/slapd-%i.pid -w /var/run/dirsrv/slapd-%i.startpid (code=exited, status=0/SUCCESS)
	Main PID: 18516 (ns-slapd)
	  CGroup: name=systemd:/system/dirsrv@.service/PKI-IPA
		  └ 18516 /usr/sbin/ns-slapd -D /etc/dirsrv/slapd-PKI-IPA -i /var/run/dirsrv/slapd-PKI-IPA.pid -w /var/run/dirsrv/slapd-PKI-IPA.startpid
[root@regular-guest slapd-PKI-IPA]# 
==============================================================================

[root@regular-guest slapd-PKI-IPA]# rpm -q freeipa-server pki-ca pki-selinux
freeipa-server-2.1.90.rc1-0.fc16.x86_64
pki-ca-9.0.20-1.fc16.noarch
pki-selinux-9.0.20-1.fc16.noarch
[root@regular-guest slapd-PKI-IPA]# 


What am I missing?

The beta version of FreeIPA v2.1.90 isn't compatible with pki-* > 9.0.18.

The pkisilent command did not previously escape shell characters so the IPA installer had to do it. The pkisilent command now does escape characters so IPA cannot, otherwise the CA installer blows up as you are seeing.

Hi

I don't know if this is exactly the same problem but I'm trying to install freeipa on a Centos 6.2 server and it's failing in the same spot. 3/17 of the certificate server install...

1.)The ipaserver-install.log is below....all other log files are devoid of data.
2.)Manual attempts to run 'service pki-cad start pki-ca' fail. I don't know how to get more information out of this process to figure it out but I suspect it's related to tomcat6...which is running by the way.
3.) Whenever I run the 'service start' command then I get another entry in the catalina.out file in /var/log/pki-ca which states "This account is currently not available"

Thanks for any help!!

===================================

Before proceeding with the configuration, make sure
the firewall settings of this machine permit proper
access to this subsystem.

Please start the configuration by accessing:

https://hammer.3forge.net:9445/ca/admin/console/config/login?pin=0ZY5ZdcaKSXSbevgEqgH

After configuration, the server can be operated by the command:

    /sbin/service pki-cad restart pki-ca


2012-05-30 14:32:39,042 DEBUG stderr=[error] FAILED run_command("/sbin/service pki-cad restart pki-ca"), exit status=1 output="Stopping pki-ca: ^[[60G[^[[0;32m  OK  ^[[0;39m]^M
Starting pki-ca: ^[[60G[^[[0;31mFAILED^[[0;39m]^M"

2012-05-30 14:32:39,042 DEBUG   duration: 6 seconds
2012-05-30 14:32:39,042 DEBUG   [3/17]: configuring certificate server instance
2012-05-30 14:32:39,431 DEBUG args=/usr/bin/perl /usr/bin/pkisilent 'ConfigureCA' '-cs_hostname' 'hammer.3forge.net' '-cs_port' '9445' '-client_certdb_dir' '/tmp/tmp-4Pn2gY' '-client_certdb_pwd' XXXXXXXX '-preop_pin' '0ZY5ZdcaKSXSbevgEqgH' '-domain_name' 'IPA' '-admin_user' 'admin' '-admin_email' 'root@localhost' '-admin_password' XXXXXXXX '-agent_name' 'ipa-ca-agent' '-agent_key_size' '2048' '-agent_key_type' 'rsa' '-agent_cert_subject' 'CN=ipa-ca-agent,O=3FORGE.NET' '-ldap_host' 'hammer.3forge.net' '-ldap_port' '7389' '-bind_dn' 'cn=Directory Manager' '-bind_password' XXXXXXXX '-base_dn' 'o=ipaca' '-db_name' 'ipaca' '-key_size' '2048' '-key_type' 'rsa' '-key_algorithm' 'SHA256withRSA' '-save_p12' 'true' '-backup_pwd' XXXXXXXX '-subsystem_name' 'pki-cad' '-token_name' 'internal' '-ca_subsystem_cert_subject_name' 'CN=CA Subsystem,O=3FORGE.NET' '-ca_ocsp_cert_subject_name' 'CN=OCSP Subsystem,O=3FORGE.NET' '-ca_server_cert_subject_name' 'CN=hammer.3forge.net,O=3FORGE.NET' '-ca_audit_signing_cert_subject_name' 'CN=CA Audit,O=3FORGE.NET' '-ca_sign_cert_subject_name' 'CN=Certificate Authority,O=3FORGE.NET' '-external' 'false' '-clone' 'false'
2012-05-30 14:32:39,431 DEBUG stdout=libpath=/usr/lib64
#######################################################################
CRYPTO INIT WITH CERTDB:/tmp/tmp-4Pn2gY
tokenpwd:XXXXXXXX
#############################################
Attempting to connect to: hammer.3forge.net:9445
Exception in LoginPanel(): java.lang.NullPointerException
ERROR: ConfigureCA: LoginPanel() failure
ERROR: unable to create CA

#######################################################################

2012-05-30 14:32:39,431 DEBUG stderr=Exception: Unable to Send Request:java.net.ConnectException: Connection refused
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:235)
        at HTTPClient.sslConnect(HTTPClient.java:326)
        at ConfigureCA.LoginPanel(ConfigureCA.java:244)
        at ConfigureCA.ConfigureCAInstance(ConfigureCA.java:1157)
        at ConfigureCA.main(ConfigureCA.j012-05-30 14:32:39,431 CRITICAL failed to configure ca instance Command '/usr/bin/perl /usr/bin/pkisilent 'ConfigureCA' '-cs_hostname' 'hammer.3forge.net' '-cs_port' '9445' '-client_certdb_dir' '/tmp/tmp-4Pn2gY' '-client_certdb_pwd' XXXXXXXX '-preop_pin' '0ZY5ZdcaKSXSbevgEqgH' '-domain_name' 'IPA' '-admin_user' 'admin' '-admin_email' 'root@localhost' '-admin_password' XXXXXXXX '-agent_name' 'ipa-ca-agent' '-agent_key_size' '2048' '-agent_key_type' 'rsa' '-agent_cert_subject' 'CN=ipa-ca-agent,O=3FORGE.NET' '-ldap_host' 'hammer.3forge.net' '-ldap_port' '7389' '-bind_dn' 'cn=Directory Manager' '-bind_password' XXXXXXXX '-base_dn' 'o=ipaca' '-db_name' 'ipaca' '-key_size' '2048' '-key_type' 'rsa' '-key_algorithm' 'SHA256withRSA' '-save_p12' 'true' '-backup_pwd' XXXXXXXX '-subsystem_name' 'pki-cad' '-token_name' 'internal' '-ca_subsystem_cert_subject_name' 'CN=CA Subsystem,O=3FORGE.NET' '-ca_ocsp_cert_subject_name' 'CN=OCSP Subsystem,O=3FORGE.NET' '-ca_server_cert_subject_name' 'CN=hammer.3forge.net,O=3FORGE.NET' '-ca_audit_signing_cert_subject_name' 'CN=CA Audit,O=3FORGE.NET' '-ca_sign_cert_subject_name' 'CN=Certificate Authority,O=3FORGE.NET' '-external' 'false' '-clone' 'false'' returned non-zero exit status 255
2012-05-30 14:32:39,433 DEBUG Configuration of CA failed
  File "/usr/sbin/ipa-server-install", line 1151, in <module>
    sys.exit(main())

  File "/usr/sbin/ipa-server-install", line 954, in main
    subject_base=options.subject)

  File "/usr/lib/python2.6/site-packages/ipaserver/install/cainstance.py", line 537, in configure_instance
    self.start_creation("Configuring certificate server", 210)

  File "/usr/lib/python2.6/site-packages/ipaserver/install/service.py", line 248, in start_creation
    method()

  File "/usr/lib/python2.6/site-packages/ipaserver/install/cainstance.py", line 680, in __configure_instance

ava:1672)

=============================================================================
java.lang.NullPointerException

Are any AVCs reported?

Created attachment 588537 [details]
Contains the avc's from audit.log

Ok, nothing obvious there.

The install is failing because it appears that dogtag is not start. Is there a java process running for the pki-ca instance? Can you telnet to it locally? Do you have iptables defined that might cause problems?

No...there's no java process for pki running. There's only one process running that appears to be of interest and that is an ns-slapd process that is being run by pkisrv...I don't know if it matters too much but the user pkisrv was created with a login shell defined and I changed that to no login shell.

I've tried the install with SELinux enabled, disabled and in permissive state. I've also tried it with iptables running with appropriate ports open but for the last few attempts the firewall has been turned off completely.

I have eclipse and java running separately on that box and tomcat6 is up and running as well.

From my first posting above...

>>3.) Whenever I run the 'service start' command then I get another entry in the catalina.out file in /var/log/pki-ca which states "This account is currently not available"

I've tracked this down to the init.d/tomcat6 file... the  "su -" command is failing immediately when trying to su to any user without a login shell defined...this include pkiuser and tomcat...I suspect tomcat was running earlier because it was being launched from within Eclipse...

anyhow I put a "-s /bin/sh" into the command line for su and am now getting stuck on various permission issues with catalina.out

so I completely uninstalled and erased from my machine ipa-server and everything that looked like tomcat...so many things were broken I felt I had to start over ....links that were setup wrong; filesystem permission problems; files that didn't exist; the tomcat init script.

So with everything off the box I did a clean download of ipa-server and re-install ....and it stopped in the same place but with different results...

1.) I still had to do the su fix that I mentioned earlier to the tomcat6 init.d file.
2.) various permission problems with /usr/share/tomcat6/logs and then with /var/log/tomcat6

3.) Catalina.out now shows a connection refused:

Jun 3, 2012 6:39:48 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:422)
        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)

I'm hoping the dogtag developers will chime in at some point...

What permission issues are you seeing? Is it because we're mixing instances being executed as different users?

As I understand it dogtag basically clones the tomcat6 startup script in an attempt to avoid all this.

I'm not a tomcat expert by any means but I'll tell you what I think so far.
My current state:
I'm running tomcat6.0.0.35.yadayada as a package. The 35 is key because from what I've been able to gather the init.d/tomcat6 script problem with su was supposed to have been fixed in package 25, so I suspect something went awry in the packaging.
Before running 'yum -y install ipa-server', I ran 'yum erase ipa-server', 'yum erase 'tomcat6', and then for good measure 'yum erase 'tomcat*'.
I then checked for the non-existence of all the tomcat directories and the init.d/tomcat6 file. There was one directory that was not cleaned up that I manually deleted and that was /var/lib/tomcat6/webapps...

so I installed ipa-server and before I ran ipa-server-install I checked the init.d/tomcat6 file and fixed that.
/var/log/tomcat6 had permissions such that pkiuser could not write to catalina.out. 

/usr/share/tomcat6 had permissions that also had to get fixed...( /usr/share/tomcat6/logs is a link to /var/log/tomcat6) so I had to adjust the permissions on /usr/share/tomcat6 and then separately to /var/log/tomcat6.

service pki-cad start pki-ca  just goes away for about 30 seconds and then exits with nothing in the catalina.out file...

Let me know if anyone can think of something else to try...

Jerome,

tomcat6.0.0.35 seems like a really old version of tomcat.  Do you mean tomcat6.6.0.35?  

Just so its clear what your environment is: please provide the following output:

rpm -q tomcat6
rpm  -q pki-ca
rpm -q pki-common
cat /etc/redhat-release

The pki-ca init script should be /var/lib/pki-ca/pki-ca - which should be a link to the tomcat6 init script.  You might try putting a set +x at the top of the script and capturing the output.  This will give us some idea as to where it is failing.

FWIW I debugged many of these tomcat6 problems about a year ago and provided fixes to David Knox (dknox) David is the tomcat6 maintainer. I'm sorry but I don't have time at the moment dig through all the tomcat6 package changes but I have the sense these parts of the tomcat6 scripts keep getting tweaked with the possibility of introducing regressions.

I think part of the problem is that there is "vanilla tomcat" with a default system provided tomcat instance and then there is tomcat's multiple instance support which runs through different configuration paths. Dogtag uses the later (non-default multiple instances). This mechanism gets less testing is is not as well understood. The type of errors described in the above comments are indicative of the non-default multiple instance configuration which do not align with the simple configuration case.

If you get really stuck you can ping me but I'm swamped at the moment with other work. I'd suggest you dig though the tomcat6 bugzilla's, most of the gory details are fully described there.

My apologies...6.6.0.35....

tomcat6-6.0.35-1.jpp5.noarch
pki-ca-9.0.3-21.el6_2.noarch
pki-common-9.0.3-21.el6_2.noarch
CentOS release 6.2 (Final)

/var/lib/pki-ca/pki-ca does link to tomcat6 and I added a line 'set +x' just before it loads the functions file.

ran 'service pki-cad start pki-ca' and there was no output to the screen...log files are empty....nothing in catalina.out

I take that back...John's comment brought something to mind because I spent a fair amount of time trolling as he suggested over the weekend. One of the things that needed to be changed to the tomcat6 setup scripts to make it multi instance was the separate creation of  .pid files in /var/run and you see this in the script itself. Just quickly checking the var/run directory I found an old pid file from several days ago..( for a few moments I somehow had managed to create a tomcat process with pkiuser as an owner). Deleting that pid file and then rerunning the service/start command has generated tons of stuff and I have another running tomcat process....not working yet...

/var/log/pki-ca/catalina.out now has the following content:
/usr/sbin/tomcat6: line 60: /usr/share/tomcat6/logs/catalina.out: Permission denied
/usr/sbin/tomcat6: line 41: /var/run/tomcat6.pid: Permission denied
/usr/sbin/tomcat6: line 41: /var/run/tomcat6.pid: Permission denied
/usr/sbin/tomcat6: line 41: /var/run/tomcat6.pid: Permission denied
/usr/sbin/tomcat6: line 41: /var/run/tomcat6.pid: Permission denied

/var/log/tomcat6/catalina.out now has permission denied on several files...


I have to say I'm not a big fan of pid files in general....

There is a change in pki-ca-9.0.3-24 that specifically relates to changes in tomcat6.

Here are the changes since 9.0.3-21:

2012-03-16 12:00:00
Ade Lee <alee> 9.0.3-24:
- BZ 802396 - Change location of TOMCAT_LOG to match tomcat6 changes

2012-03-05 12:00:00
Matthew Harmsen <mharmsen> 9.0.3-22:
- Resolves #745677 - Firefox Launcher on Panel being modified for all users.
(fixed in Git repo)

2012-03-05 12:00:00
Ade Lee <alee> 9.0.3-23:
- Resolves #769388 - pki-silent does not properly escape command-line arguments
(fixed in Git repo)

You are probably running into the issue fixed in 9.0.3-24, and once that is fixed, will run into the issue fixed in 9.0.3-23

So, please upgrade your pki-* packages to 9.0.3-24

ok....hate to be a numnutz but do you know where can I get that package?

yum doesn't work?

yum list pki-common

The packages are in RHEL, so I would think they would be available.

no...:-)  it tells me I have the latest and greatest

I have Centos-Base/Debuginfo/fasttrack/Media repos as well as epel and jpackage set up under yum.repos.d

I'm trying to google it but no joy yet....

Jerome, 

I'm not really familiar with the centos repos, but this is something that is easier resolved over #irc.  Perhaps you can join #freeipa or #dogtag-pki on freenode.

Someone else who is more familiar with centos can also jump in there.

no probs...I'll figure it out then redo the install and let you know...

I don't think this version exists anywhere for me to download...Is this something I can work through or should I just throw in the towel on freeipa?

The version that Ade is referring to will be in 6.3 and was available in the 6.3 beta. I can't seem to find it externally anywhere.

Jerome, I've gathered that you are on CentOS, can you provide the versions of ipa-server, 389-ds-base and pki-ca that you have installed?

ipa-server-2.1.3-9.el6.x86_64
389-ds-base-1.2.9.14-1.el6_2.2.x86_64
pki-ca-9.0.3-21.el6_2.noarch

Is there anyway I can shake that patch free before the upgrade? I'm not sure how the packaging works  between RHEL, Fedora and Centos and others but I can't see how this would be installable on any platform... and I'm clearly willing to help test the package to make sure it works....I need to go stop the bleeding from banging my head against the wall....:-)

Jerome, 

So what happened was - tomcat6 changed the way they use the variables in their init script, and this broke the dogtag install.  We fixed the dogtag install - but you're in a pickle because it sounds like you have the tomcat changes, but not the requisite dogtag changes.

The best option would be to find the relevant dogtag packages.  These might be available in wherever repo Centos 6.3 packages are located.

Another option would be to manually apply the changes required.  This is easy to do because all the relevant changes are in scripts.

The changes are as follows:

Prior to running ipa-server-install, make the following changes:

1. In  /usr/share/pki/ca/conf/tomcat6.conf, change :
TOMCAT_LOG="[TOMCAT_LOG_DIR]/catalina.out" 
to: 
TOMCAT_LOG="[TOMCAT_LOG_DIR]/tomcat-initd.log"

2. In /usr/bin/pkisilent, change the following line:

my $output = `java -cp $ENV{CLASSPATH} com.netscape.pkisilent.PKISilent @ARGV`;

to: 

my @args = ();
foreach (@ARGV) {
    push(@args, quotemeta($_));
}
my $output = `java -cp $ENV{CLASSPATH} com.netscape.pkisilent.PKISilent @args`;

The quoting will likely break IPA. Only one side is allowed to do it and if both do then the dogtag install dies quickly. Currently IPA does it.

Ade,

Here's the relevant line of  /usr/bin/pkisilent:

my $output = `java -cp $ENV{CLASSPATH} @ARGV`

should I just concentrate on putting quotes around the argument list or add the rest of it as well.

The tomcat6 packaging team needs to add the  "-s /bin/sh" back into the tomcat6 script as well...


Rob,
I'm not sure what you mean by 'sides'...

If both ipa-server-install and pkisilent try to escape arguments then pkisilent will blow up. In 2.1.3 ipa-server-install is escaping arguments to pkisilent, so pkisilent should not. Or you can make a 2-line change to ipaserver/cainstance.py to make IPA not do the shell escape, it's up to you.

Got it. I'm not sure I know the answer...I'd like to see pki-cad start up without errors before tackling the install again and that's not happening yet.


Does pkisilent only run inside the ipa-server-install process? 

what do I need to do to the python script? I have it open now....

edit /usr/lib/python-*/site-packages/ipaserver/install/cainstance.py

Remove or comment out this line:

            args[2:] = [ipautil.shell_quote(i) for i in args[2:]]

pkisilent is only executed during server installation.

Thanks Rob, Ade but I guess I'll have to put a hold on this for awhile. The tomcat6 scripts have some pretty basic problems that have nothing to do with ipa-server and I'm not sure just how to fix them. I can tell you that the scripts that were installed will always look for both a /var/run/tomcat6.pid file and a pki-ca.pid file and that the pki-ca.pid file will always be empty. I can also state that you won't see a pki-ca entry in the /var/lock/subsys directory...

As a result...service pki-cad stop pki-ca will not be able to actually stop a running process and you can't start one properly without the existence of a running tomcat6 process....expressly one started with service tomcat6 start because it needs the tomcat6.pid file. But you cannot run these two commands consecutively...
service tomcat6 start
service pci-cad start pci-ca

because they both will try and use the exact same ports etc...

The running instance that finally get instantiated throws 'java.net.BindException: Permission denied <null>:8080' into the log file.
if tomcat6 has an instance running as well then the logs read that there is a clash not  permission denied..


Anyways...I've made the change above to cainstance.py and it still stops in the exact same spot. I also made the first change that Ade recommended and that output file is never created...it keeps writing only to catalina.out....

If I can try something else out for you then just ping me...

Jerome, 

I'm confused as to why you're running into all these problems with tomcat6 and dogtag.  Dogtag and tomcat6 have been working correctly together on rhel 6.3 as well as on various versions of fedora.  That said, I appreciate you trying to figure out what could be causing the problems.

First off, tomcat6 should not be trying to look for a tomcat6.pid file.  Why?  The way this works is that pkicreate (which is called by the ipa server install scripts) creates a new tomcat instance which resides under /var/lib/pki-ca

This instance uses the default tomcat6 install script to start (as linked to /var/lib/pki-ca/pki-ca), but it also parses a config file at /etc/sysconfig/pki/ca/pki-ca, which overrides many tomcat defaults including pid files.

So, I would do the following:

1. Make sure there are no java processes running.  Remove any pid files for tomcat or pki-ca etc.  You should not start the tomcat6 default instance using the tomcat6 init scripts. 

2, Put selinux in permissive mode.  (Not disabled).

3. Do "service pki-cad restart".  At this point, you should be able to find some logs in catalina.out or other tomcat files.  If not, then I would add set +x in the /etc/init.d/pki-cad and the tomcat files to see what is actually being executed and capture the output.  In particular, I'd be looking  to see if the relevant config file is being read.

4. As the problems you are seeing are related to some kind of conflict between tomcat6 init scripts and dogtag, I would suggest downgrading the tomcat6 version until it works.  That would pinpoint what is causing things to break.

In the meantime, I'll see if I can install a VM with those versions of tomcat6 and dogtag and see what is happening.

Ade, I think he's on the equivalent of RHEL 6.2 (running CentOS).

Ade,
Rob is correct and I apologize if I that wasn't clear but I assure you that I've done everything that you're suggesting and quite a bit more. It would take nothing more than to download the packages onto a fresh machine for you to verify that I'm not crazy. I am confident that at the very least the init.d/tomcat6 file will need to be immediately modified after the package install or nothing will work...certainly not the ipa-server-install script. An example: pkiuser is added to the system with no login shell and yet the tomcat6 script tries to execute an 'su' command with a -c "script" argument and it will stop immediately. 

And that's just for starters. I don't believe the problem is a conflict with tomcat6 and dogtag... I think there's a problem with the tomcat6.x.x.35 package. For any application that needs to run under a different user....the tomcat user had a defined shell so just running tomcat6 worked fine.

Anyways, I'm still hanging on to my enthusiasm for trying out dogtag and freeipa so if there's something concrete for me to try then I'll hop right to it.

Jerome, 

So, I just confirmed that using the latest dogtag code with the tomcat6 version you are using works on fedora 15.

I believe you're not crazy though - so I'll try to reproduce on a rhel 6.2 system.  Maybe the tomcat6 init scripts are different on a rhel/centos system.

Here is how it is supposed to work:
1. service pki-cad start pki-ca runs the init.d/pki-cad script.  This script sources the file /usr/share/pki/scripts/functions and calls the function start()/stop() etc.
2. The start function parses /etc/sysconfig/pki/ca/pki-ca - which has values that override the default tomcat parameters (including pids).  This file also provides the variable PKI_INSTANCE_INITSCRIPT, which is /var/lib/pki-ca/pki-ca which is then executed to start tomcat.
3. /var/lib/pki-ca/pki-ca is actually a link to /etc/rc.d/init.d/tomcat6.  So, this is where the tomcat6 init script is executed.

Anyways, please put set -x at the top of the /etc/rc.d/init.d/tomcat6 file and try to restart the server.  Please capture the output and attach both the output and the relevant tomcat6 init script.

Thanks, 
Ade

Ok. The set +x has been there for a couple of days since you asked me to do this last time....
No processes running...no pid files...running service pki-cad restart pki-ca:

Stopping pki-ca:      [  OK  ]
Starting pki-ca:      [FAILED]  <---Should not be happening...looking for tomcat6.pid instead....

Pid files:
No tomcat6.pid but 1 EMPTY pki-ca.pid file.
-rw-r--r--. 1 pkiuser pkiuser 0 Jun  8 11:13 /var/run/pki-ca.pid

/var/lock/subsys has neither tomcat6 nor pki-ca

One process running:
pkiuser  27939     1  0 11:13 ?        00:00:04 /usr/bin/java -classpath :/usr/share/tomcat6/bin/bootstrap.jar:/usr/share/tomcat6/bin/tomcat-juli.jar:/usr/share/java/commons-daemon.jar -Dcatalina.base=/usr/share/tomcat6 -Dcatalina.home=/usr/share/tomcat6 -Djava.endorsed.dirs= -Djava.io.tmpdir=/var/cache/tomcat6/temp -Djava.util.logging.config.file=/usr/share/tomcat6/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager org.apache.catalina.startup.Bootstrap start

the /var/log/pki-ca/tomcat-initd.log has a single entry:
/usr/sbin/tomcat6: line 44: /var/run/tomcat6.pid: Permission denied

the /var/log/tomcat6/catalina.out has the following entries....
catalina.out:SEVERE: The scratchDir you specified: /usr/share/tomcat6/work/Catalina/localhost/manager is unusable.
catalina.out:SEVERE: The scratchDir you specified: /usr/share/tomcat6/work/Catalina/localhost/host-manager is unusable.
catalina.out:SEVERE: The scratchDir you specified: /usr/share/tomcat6/work/Catalina/localhost/examples is unusable.
catalina.out:SEVERE: The scratchDir you specified: /usr/share/tomcat6/work/Catalina/localhost/_ is unusable.
catalina.out:SEVERE: The scratchDir you specified: /usr/share/tomcat6/work/Catalina/localhost/sample is unusable.


So far we're right where we have been except that I can now connect to tomcat on port 8080! Those errors are missing from the file as well.

netstat -anp | grep 8080 now returns 
tcp        0      0 0.0.0.0:8080                0.0.0.0:*                   LISTEN      27939/java

When before it was nothing.
I'm going to try and see if this is enough to get pass the install

Created attachment 590464 [details]
/etc/rc.d/init.d/tomcat6 file

ok.

1.)Ran ipa-server-install --uninstall
      I still have a pkiuser owned tomcat process running. 

2.)service pki-cad stop pki-ca
       This machine contains no registered 'pki-ca' subsystem instance!

3.)ls -l /var/run/pki-ca.pid
-rw-r--r--. 1 pkiuser pkiuser 0 Jun  8 11:13 /var/run/pki-ca.pid

killing the process and cleaning up manually
process is gone....pid file is gone...netstat shows nothing listening on 8080

and 
ipa-server-install still fails in the exact same spot and for the same reason AND there's a running pkiuser/tomcat process running. 

running service pki-cad stop pki-ca:

Stopping pki-ca:                                           [  OK  ]
yet the process is still running...

All of this pid file logic has to work for the whole process to work!!

Anyways...let me know if there's something else you want me to try...

Created attachment 590466 [details]
tomcat output file

Created attachment 590467 [details]
I added all the environment variables as well...to help debug

Jerome, did tomcat6-6.0.35 ship with CentOS? This seems to be a higher version than is in RHEL and seems to be the source of the problem.

It's the version that gets downloaded with the ipaserver, yes. I started to do a downgrade of tomcat6 via yum and it threatened to deinstall big chunks of pki so I left it alone. I was going to finish what I'm working on and then try to port the whole ipa-server process to work with tomcat7 over the weekend...

I can't say I did an exhaustive search of centos mirror repositories but I did look at 3 or 4 and they all have the version 6.0.35....

I'm not sure there is a lot we can do. It would appear that the tomcat6 in centOS has a problem creating a pid file with the proper permissions. This version is not equivalent to what is in RHEL 6.2, I'm not really sure why since centOS is supposed to be a clone. We are having similar problems with tomcat6 and pid files in F-18, probably the same bug.

There are a number of things that could be tried but they would likely involve either hacking on tomcat6 files or downgrading packages without deps. In either case you'd end up with a fragile installation.

Well I was hoping for for a better solution but this is kind of where I thought we'd probably end up...getting this to work with Tomcat 7 seems like the most logical path since the integration seems fairly loose and I have Teamcity running and that needs tomcat7 anyways. I'll let you know if I get it working....

For what it's worth, it's not a permissioning problem with the pid file it's the different variable names that are being used as you traverse the various scripts.
/usr/sbin/tomcat6 on line 44 is using a variable that never changes from the default of tomcat6 while other parts of the scripts are using different variables to control the process...

Thanks to everyone for their efforts!

It might be worth asking the centOS folks why they have diverged from the tomcat shipped in RHEL-6. It may be that they can come up with a fix for this.

We are kind of stuck since it currently works in F-17, it works in RHEL 6.2 (and will in 6.3). It is broken in F-18 but being worked on, maybe that will help you. But we have no control over what centOS ships and that seems to be where the problem lies.

afaik, Jerome is not using the CentOS provided tomcat6 version:
http://mirror.centos.org/centos/6/updates/x86_64/Packages/tomcat6-6.0.24-36.el6_2.noarch.rpm

This is NOT the package that the ipaserver package installed. I've installed and de-installed it too many times now...

Should I erase ipaserver then download tomcat6 then download the ipaserver? 
If so then I've done that and still ended up in the same place. I've been trying to get ipa up and running since April now...

I just uninstalled everything again and reinstalled the ipa package and it pulled down the 6.0.24 package!!!! Life is good. ipa-server-install just successfully completed....

No clue what changed but I've got a running instance of freeipa now and thanks to everyone for their help!

We seem to have four completely different problems all rolled into this one bug.

I believe that Thorsten still has an open issue, is this correct?

Let me clarify. I believe that all of the issues have been resolved/explained with the exception of Thorsten's issue. At last check the problem seemed to be that the dogtag 389-ds instance was not restarted.

Do you still have this install or can you try to reproduce again? If you still have it, can you try to manually start the dogtag dirsrv instance? service dirsrv@PKI-CA start

Is there anything in the PKI-CA dirsrv instance error log that would indicate why it wasn't running?