RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 905064 - ipa install error Unable to find preop.pin
Summary: ipa install error Unable to find preop.pin
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: ipa
Version: 6.5
Hardware: Unspecified
OS: Unspecified
medium
unspecified
Target Milestone: rc
: 6.5
Assignee: Martin Kosek
QA Contact: Namita Soman
URL:
Whiteboard:
Depends On:
Blocks: 1061410
TreeView+ depends on / blocked
 
Reported: 2013-01-28 13:54 UTC by Scott Poore
Modified: 2014-11-18 10:31 UTC (History)
8 users (show)

Fixed In Version: ipa-3.0.0-38.el6
Doc Type: Bug Fix
Doc Text:
Cause: An intermittent race condition happened when ipa-server-install tried to read preop.pin value from CS.cfg, which was not yet written to the disk by pkicreate. Consequence: The IPA server installation failed. Fix: The ipa-server-install was altered to anticipate such race condition. In case of not being able to read the preop.pin value from the CS.cfg, it halts until it times out or the value is written to the disk. Result: If race condition happens, the installation does not crash, but installer rather waits until preop.pin value is available. Situation is properly logged in the installation log.
Clone Of:
Environment:
Last Closed: 2014-10-14 07:32:10 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2014:1383 0 normal SHIPPED_LIVE ipa bug fix and enhancement update 2014-10-14 01:21:36 UTC

Description Scott Poore 2013-01-28 13:54:59 UTC
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:

Comment 2 Martin Kosek 2013-01-28 16:04:15 UTC
Upstream ticket:
https://fedorahosted.org/freeipa/ticket/3382

Comment 4 Tomas Babej 2013-04-04 15:25:27 UTC
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 RHEL 7 will have Dogtag 10, this should not be a bug against it.

Comment 11 Scott Poore 2013-12-11 14:56:11 UTC
Re-opening this one as I've seen it several times in automated tests recently.  Enough that it is disrupting RHEL6.x testing.

Comment 15 Brian J. Murrell 2014-02-21 14:55:25 UTC
Yes, indeed, I am seeing this on RHEL 6.5 also.  It seems to happen about 50% of the time but in an environment where you are automating system setup, this kind of failure rate is catastrophic.

Additionally, it seems that when this happens "ipa-server-install" is not even returning with a non-zero exit code to indicate the failure.

Is there any way to rectify this error in situ or does the installation need to be completely written off and restarted from scratch?

Trying to repeat the installation after doing an "--uninstall" yields the following:

Configuring directory server for the CA (pkids): Estimated time 30 seconds
  [1/3]: creating directory server user
  [2/3]: creating directory server instance
  [3/3]: restarting directory server
Done configuring directory server for the CA (pkids).
Configuring certificate server (pki-cad): Estimated time 3 minutes 30 seconds
  [1/20]: creating certificate server user
  [2/20]: configuring certificate server instance
ipa         : CRITICAL failed to configure ca instance Command '/usr/bin/perl /usr/bin/pkisilent ConfigureCA -cs_hostname ipa-1.example.com -cs_port 9445 -client_certdb_dir /tmp/tmp-YbJ9Aa -client_certdb_pwd XXXXXXXX -preop_pin abc123 -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=EXAMPLE.COM -ldap_host ipa-1.example.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=EXAMPLE.COM -ca_subsystem_cert_subject_name CN=CA Subsystem,O=EXAMPLE.COM -ca_ocsp_cert_subject_name CN=OCSP Subsystem,O=EXAMPLE.COM -ca_server_cert_subject_name CN=ipa-1.example.com,O=EXAMPLE.COM -ca_audit_signing_cert_subject_name CN=CA Audit,O=EXAMPLE.COM -ca_sign_cert_subject_name CN=Certificate Authority,O=EXAMPLE.COM -external false -clone false' returned non-zero exit status 255
Configuration of CA failed

IIRC, analysing this, that perl command is trying to connect to localhost on port 389 but there is nothing listening on that port.  ns-slapd is listening on port 7389.

So even a working clean-up procedure would be appreciated so that we can at least try a "redo" to see if we can get lucky and avoid the race without having to completely scrub the node and re-install the O/S from scratch.  Barring a solution or workaround to the race that is.

Comment 16 Martin Kosek 2014-02-24 08:26:51 UTC
Hello Brian, thanks for your report. I think you are hitting actually 2 bugs:

1) The infamous preop-pin race condition happening in FreeIPA < 3.1 (read RHEL-6.x). This is something we would like to fix in RHEL 6.6.

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

2) Installer does not always properly record that PKI was configured and if the installer crashes before that moment, it does not uninstall PKI which may cause the issue you see.

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


To workaround 2) I would recommend running "ipa-server-install --uninstall --unattended" several times + also running manual removal of PKI instance after this crash occurs:

/usr/bin/pkiremove -pki_instance_root=/var/lib -pki_instance_name=pki-ca --force


To workaround 1) I am thinking the best way would be to make pkicreate run longer so that it has time to create the preop.pin file before the installer queries it. Something like this should do the trick:

# echo -e '#!/bin/sh\npkicreate "$@"\nRET=$?\nsleep 10\nexit $RET' > /root/pkicreate_with_wait
# chmod +x /root/pkicreate_with_wait
# alias pkicreate=/root/pkicreate_with_wait
# ipa-server-install ...

Comment 17 Martin Kosek 2014-06-13 07:37:02 UTC
Fixed upstream
ipa-3-0:
https://fedorahosted.org/freeipa/changeset/1ec270e5d2fee90605578d04047d675a51318245

Comment 20 Michael Gregg 2014-07-16 18:10:13 UTC
Verified on: 
ipa-server-3.0.0-25.el6.i686
pki-ca-9.0.3-30.el6.noarch


The installs seem to get past the CA setup rather well. 

No failures reported in the last few weeks:

Example output from a i686 run:

Done configuring directory server for the CA (pkids).
Configuring certificate server (pki-cad): Estimated time 3 minutes 30 seconds
  [1/21]: creating certificate server user
  [2/21]: creating pki-ca instance
  [3/21]: configuring certificate server instance
  [4/21]: disabling nonces
  [5/21]: creating CA agent PKCS#12 file in /root
  [6/21]: creating RA agent certificate database
  [7/21]: importing CA chain to RA certificate database
  [8/21]: fixing RA database permissions
  [9/21]: setting up signing cert profile
  [10/21]: set up CRL publishing
  [11/21]: set certificate subject base
  [12/21]: enabling Subject Key Identifier
  [13/21]: setting audit signing renewal to 2 years
  [14/21]: configuring certificate server to start on boot
  [15/21]: restarting certificate server
  [16/21]: requesting RA certificate from CA
  [17/21]: issuing RA agent certificate
  [18/21]: adding RA agent as a trusted user
  [19/21]: configure certificate renewals
  [20/21]: configure Server-Cert certificate renewal
  [21/21]: Configure HTTP to proxy connections
Done configuring certificate server (pki-cad).
Configuring directory server (dirsrv): Estimated time 1 minute

Comment 21 errata-xmlrpc 2014-10-14 07:32:10 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHBA-2014-1383.html


Note You need to log in before you can comment on or make changes to this bug.