https://bugzilla.redhat.com/show_bug.cgi?id=905064 (Red Hat Enterprise Linux 6)
Description of problem: On some i386 servers I'm seeing the following during ipa-server-install and sometimes during ipa-replica-install: 2013-01-25T02:58:44Z DEBUG [3/21]: configuring certificate server instance 2013-01-25T02:58:44Z INFO File "/usr/lib/python2.6/site-packages/ipaserver/install/installutils.py", line 614, in run_script return_value = main_function() File "/usr/sbin/ipa-server-install", line 942, in main subject_base=options.subject) File "/usr/lib/python2.6/site-packages/ipaserver/install/cainstance.py", line 617, in configure_instance self.start_creation(runtime=210) File "/usr/lib/python2.6/site-packages/ipaserver/install/service.py", line 358, in start_creation method() File "/usr/lib/python2.6/site-packages/ipaserver/install/cainstance.py", line 790, in __configure_instance self.server_root, self.dogtag_constants.PKI_INSTANCE_NAME) File "/usr/lib/python2.6/site-packages/ipaserver/install/cainstance.py", line 124, in get_preop_pin raise RuntimeError("Unable to find preop.pin in %s. Is your CA already configured?" % filename) 2013-01-25T02:58:44Z INFO The ipa-server-install command failed, exception: RuntimeError: Unable to find preop.pin in /var/lib/pki-ca/conf/CS.cfg. Is your CA already configured? And when I log into the failed master this was from, I can see this: [root@cloud-qe-3 log]# grep preop.pin /var/lib/pki-ca/conf/CS.cfg|sed 's/preop.pin=[a-Z0-9]*$/preop.pin=XXXXXXXXXXXXXX/' preop.pin=XXXXXXXXXXXXXX After some debugging, Ade Lee from Dev found this: ----- Original Message ----- > > The failure occurs in cainstance.py (the ipa install scripts) after > pkicreate has run, and before pkisilent is run. > > pkicreate completes successfully and the pin is stored in the CS.cfg. > I extracted and the ipa code that is run to get the pin, and it > returns > the correct value. > > The code looks like this: > > def get_preop_pin(instance_root, instance_name): > # Only used for Dogtag 9 > preop_pin = None > > filename = instance_root + "/" + instance_name + "/conf/CS.cfg" > > # read the config file and get the preop pin > try: > f=open(filename) > except IOError, e: > root_logger.error("Cannot open configuration file." + str(e)) > raise e > data = f.read() > data = data.split('\n') > pattern = re.compile("preop.pin=(.*)" ) > for line in data: > match = re.search(pattern, line) > if (match): > preop_pin=match.group(1) > break > > if preop_pin is None: > raise RuntimeError("Unable to find preop.pin in %s. Is your > CA already configured?" % filename) > > which means, I think, that if the IPA script were unable to read the > config file, it would have raised a different exception. > > The only thing that could be happening here is some kind of race > condition where the ipa install scripts are reading the CS.cfg prior > to > it being written to disk. If I do a stat > on /var/lib/pki-ca/conf/CS.cfg, I see: > > Access: 2013-01-25 11:31:41.031896697 -0500 > Modify: 2013-01-24 21:58:44.557951715 -0500 > Change: 2013-01-24 21:58:44.561951715 -0500 > > and in the ipa-install log, we have the error occurring at > 2013-01-25T02:58:44Z. Ignoring the difference in the hours (local > vs. > UTC?), its possible this race condition might have happened. > > In fact, it looks like we go directly from running pkicreate, to > getting > the pin, to running pkisilent. There is the potential of a race > condition in this sequence. It is probably better to: > > 1. run pkicreate > 2. check that CA is up > 3. get pin > 4. run pkisilent > > Ade Version-Release number of selected component (if applicable): At least on 3.0.0-22.el6 How reproducible: I have been seeing it on automated tests noticeably but, have not been able to reproduce it manually yet. Steps to Reproduce: 1. ipa-server-install to setup a master on RHEL6 i386 build. Actual results: preop.pin failure Expected results: no failure Additional info:
This milestone is retired, moving the ticket to Triage to rescope it.
This particular code branch is called upon only with Dogtag 9 (as can be even seen in the comment of the referenced function in the description of the bug).
With Dogtag 10, we do not read CS.cfg in similiar manner and therefore such race condition would not happen. Since we no longer support Dogtag 9 installs, this should not be an issue.
As a data point, IRC user basic` basic@osuosl/staff/basic “Rudy Grigar” reported the problem on a x86_64 VM (unspecified what version of IPA and what distro).
Revive the ticket since bug 905064 is still alive and reproduced on RHEL 6.5
When fixing this ticket, do it simple:
api.env.startup_timeout
ipa-3-0:
Metadata Update from @mkosek: - Issue assigned to tbabej - Issue set to the milestone: FreeIPA 3.0.3 (bug fixing)
Login to comment on this ticket.