While CS subsystem installation, "pkispawn in silent mode" fails sometimes with exit status=1 .So my assumption is, if the Installation fails port binding should not happen and pid shouldn't be created but i see that pid is generated and ports are also getting binded.
Steps to Reproduce:
1. This can be easily reproduced in case of any kind of failure like OSError,Parsing error. 2. Just start pkispawn.
Actual results:
Ports are getting binded and pid is getting generated
Expected results:
Until we have a clean installation with execution status 0 port and pid should not be picked.
Additional info:
Here are some logs snip: Below mentioned are few cases where i saw this behavior: 1. Due to OSError. <Log snip> 2016-01-11 04:21:26 pkispawn : ERROR ....... OSError: [Errno 12] Cannot allocate memory! 2016-01-11 04:21:26 pkispawn : DEBUG ....... Error Type: OSError 2016-01-11 04:21:26 pkispawn : DEBUG ....... Error Message: [Errno 12] Cannot allocate memory 2016-01-11 04:21:26 pkispawn : DEBUG ....... File "/usr/sbin/pkispawn", line 597, in main rv = instance.spawn(deployer) File "/usr/lib/python2.7/site-packages/pki/server/deployment/scriptlets/confi guration.py", line 112, in spawn data = deployer.config_client.construct_pki_configuration_data() File "/usr/lib/python2.7/site-packages/pki/server/deployment/pkihelper.py", line 3992, in construct_pki_configuration_data self.set_admin_parameters(data) File "/usr/lib/python2.7/site-packages/pki/server/deployment/pkihelper.py", line 4403, in set_admin_parameters None, None, True) File "/usr/lib/python2.7/site-packages/pki/server/deployment/pkihelper.py", line 2637, in generate_certificate_request subprocess.check_call(command, stdout=fnull, stderr=fnull) File "/usr/lib64/python2.7/subprocess.py", line 537, in check_call retcode = call(*popenargs, **kwargs) File "/usr/lib64/python2.7/subprocess.py", line 524, in call return Popen(*popenargs, **kwargs).wait() File "/usr/lib64/python2.7/subprocess.py", line 711, in __init__ errread, errwrite) File "/usr/lib64/python2.7/subprocess.py", line 1224, in _execute_child self.pid = os.fork() <log snip ends> 2. Due to parse exception. <Log snip> 2016-01-12 03:55:14,294 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - pkispawn : INFO ....... constructing PKI configuration data. 2016-01-12 03:55:14,294 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - pkispawn : INFO ....... executing 'certutil -R -d /opt/FoobarTPS/tps/alias -s cn=PKI Administrator,e=tpsadmin@os1.phx2.redhat.com,o=Foobar2.org -k ec -q nistp256 -z /opt/FoobarTPS/tps/alias/noise -f /opt/FoobarTPS/tps/password.conf -o /opt/FoobarTPS/tps/alias/admin_pkcs10.bin' 2016-01-12 03:55:14,362 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - pkispawn : INFO ....... rm -f /opt/FoobarTPS/tps/alias/noise 2016-01-12 03:55:14,363 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - pkispawn : INFO ....... BtoA /opt/FoobarTPS/tps/alias/admin_pkcs10.bin /opt/FoobarTPS/tps/alias/admin_pkcs10.bin.asc 2016-01-12 03:55:14,699 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - pkispawn : INFO ....... configuring PKI configuration data. 2016-01-12 03:56:11,423 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - 2016-01-12 03:56:11,423 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - Installation failed. 2016-01-12 03:56:11,423 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - 2016-01-12 03:56:11,423 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - pkispawn : ERROR ....... Exception from Java Configuration Servlet: 500 Server Error: Internal Server Error 2016-01-12 03:56:11,423 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - pkispawn : ERROR ....... ParseError: not well-formed (invalid token): line 1, column 0: {"Attributes":{"Attribute":[]},"ClassName":"com.netsc ape.certsrv.base.PKIException","Code":500,"Message":"Errors in registering TPS to CA, TKS or KRA: com.netscape.certsrv.base.PKIException: Error in generating and exporting shared secret: java.security.InvalidKeyException: Key is not the right type for this algorithm"} 2016-01-12 03:56:11,423 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - pkispawn : DEBUG ....... Error Type: ParseError 2016-01-12 03:56:11,423 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - pkispawn : DEBUG ....... Error Message: not well-formed (invalid token): line 1, column 0 2016-01-12 03:56:11,423 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - pkispawn : DEBUG ....... File "/usr/sbin/pkispawn", line 597, in main 2016-01-12 03:56:11,423 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - rv = instance.spawn(deployer) 2016-01-12 03:56:11,424 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - File "/usr/lib/python2.7/site-packages/pki/server/deployment/scriptle ts/configuration.py", line 116, in spawn 2016-01-12 03:56:11,424 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - json.dumps(data, cls=pki.encoder.CustomTypeEncoder)) 2016-01-12 03:56:11,424 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - File "/usr/lib/python2.7/site-packages/pki/server/deployment/pkihelper.py", line 3872, in configure_pki_data 2016-01-12 03:56:11,424 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - root = ET.fromstring(e.response.text) 2016-01-12 03:56:11,424 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 1300, in XML 2016-01-12 03:56:11,424 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - parser.feed(text) 2016-01-12 03:56:11,424 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 1642, in feed 2016-01-12 03:56:11,424 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - self._raiseerror(v) 2016-01-12 03:56:11,424 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 1506, in _raiseerror 2016-01-12 03:56:11,424 - pki.testlib.common.Qe_class.QeHost.geetika.cmd10 - DEBUG - raise err <Log snip ends> Pid/port details : netstat -pan | grep 16443 tcp6 0 0 :::16443 :::* LISTEN 21691/java ps -ef | grep 21691 pkiuser 21691 1 33 03:54 ? 00:00:35 /usr/lib/jvm/jre/bin/java -DRESTEASY_LIB=/usr/share/java/resteasy-base -Djava.library.path=/usr/lib64/nuxwdog-jni -classpath /usr/share/tomcat/bin/boo tstrap.jar:/usr/share/tomcat/bin/tomcat-juli.jar:/usr/share/java/commons-daemon .jar -Dcatalina.base=/var/lib/pki/FoobarTPS -Dcatalina.home=/usr/share/tomcat -Djava.endorsed.dirs= -Djava.io.tmpdir=/var/lib/pki/FoobarTPS/temp -Djava.util.logging.config.file=/var/lib/pki/FoobarTPS/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.security.manager -Djava.security.policy==/var/lib/pki/FoobarTPS/conf/catalina.policy org.apache.catalina.startup.Bootstrap start root 22575 14694 0 03:56 pts/3 00:00:00 grep --color=auto 2169
When deploying a new subsystem, pkispawn will execute several operations including:
So if the subsystem deployment fails for any reason, pkispawn should stop immediately, but by that time the Tomcat is already running and bound to the port.
I think the current pkispawn behavior is fine. The pkispawn should not shutdown Tomcat because it may affect other subsystems already deployed, and it will complicate troubleshooting. Applications using the pkispawn (i.e. IPA, test scripts) should be aware of this behavior.
However, instead of shutting down Tomcat on pkispawn failure, the pkidestroy should clean up the system back to the state before pkispawn was run. So pkidestroy should work like this:
If pkidestroy does not work as described above please open a new ticket. Thanks.
Metadata Update from @gkapoor: - Issue set to the milestone: 10.3.0
Dogtag PKI is moving from Pagure issues to GitHub issues. This means that existing or new issues will be reported and tracked through Dogtag PKI's GitHub Issue tracker.
This issue has been cloned to GitHub and is available here: https://github.com/dogtagpki/pki/issues/2293
If you want to receive further updates on the issue, please navigate to the GitHub issue and click on Subscribe button.
Subscribe
Thank you for understanding, and we apologize for any inconvenience.