Bug 1260663

Summary: crash of ipa-dnskeysync-replica component during ipa-restore
Product: Red Hat Enterprise Linux 7 Reporter: Kaleem <ksiddiqu>
Component: ipaAssignee: IPA Maintainers <ipa-maint>
Status: CLOSED ERRATA QA Contact: Namita Soman <nsoman>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 7.2CC: mbasti, mkosek, pvoborni, rcritten, tlavigne
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: ipa-4.2.0-10.el7 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 1300348 (view as bug list) Environment:
Last Closed: 2015-11-19 12:06:19 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
crash log info none

Description Kaleem 2015-09-07 12:23:13 UTC
Description of problem:
During automated execution of ipa-backup/restore feature, following two crashes seen.

backtrace:
:ipautil.py:373:run:CalledProcessError: Command ''/usr/libexec/ipa/ipa-dnskeysync-replica'' returned non-zero exit status 1
:
:Traceback (most recent call last):
:  File "/usr/libexec/ipa/ipa-dnskeysyncd", line 112, in <module>
:    while ldap_connection.syncrepl_poll(all=1, msgid=ldap_search):
:  File "/usr/lib64/python2.7/site-packages/ldap/syncrepl.py", line 405, in syncrepl_poll
:    self.syncrepl_refreshdone()
:  File "/usr/lib/python2.7/site-packages/ipapython/dnssec/keysyncer.py", line 113, in syncrepl_refreshdone
:    self.hsm_replica_sync()
:  File "/usr/lib/python2.7/site-packages/ipapython/dnssec/keysyncer.py", line 170, in hsm_replica_sync
:    ipautil.run([paths.IPA_DNSKEYSYNCD_REPLICA])
:  File "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 373, in run
:    raise CalledProcessError(p.returncode, arg_string, stdout)
:CalledProcessError: Command ''/usr/libexec/ipa/ipa-dnskeysync-replica'' returned non-zero exit status 1
:
:Local variables in innermost frame:
:p_in: None
:nolog: ()
:suplementary_groups: []
:preexec_fn: None
:arg_string: "'/usr/libexec/ipa/ipa-dnskeysync-replica'"
:stdout: ''
:p_out: -1
:p_err: -1
:runas: None
:stdin: None
:skip_output: False
:timeout: None
:capture_output: True
:p: <subprocess.Popen object at 0x6107f10>
:stderr: 'ipa: WARNING: session memcached servers not running\nipa         : DEBUG    Kerberos principal: ipa-dnskeysyncd/cloud-qe-3.testrelm.test\nipa         : DEBUG    Initializing principal ipa-dnskeysyncd/cloud-qe-3.testrelm.test using keytab /etc/ipa/dnssec/ipa-dnskeysyncd.keytab\nipa         : DEBUG    using ccache /tmp/ipa-dnskeysync-replica.ccache\nipa         : DEBUG    Attempt 1/5: success\nipa         : DEBUG    Got TGT\nipa         : DEBUG    Connecting to LDAP\nipa.ipaserver.plugins.ldap2.ldap2: DEBUG    Created connection context.ldap2_46913424\nipa         : DEBUG    Connected\nTraceback (most recent call last):\n  File "/usr/libexec/ipa/ipa-dnskeysync-replica", line 171, in <module>\n    open(paths.DNSSEC_SOFTHSM_PIN).read())\n  File "/usr/lib/python2.7/site-packages/ipapython/dnssec/localhsm.py", line 97, in __init__\n    self.p11 = _ipap11helper.P11_Helper(slot, pin, library)\n_ipap11helper.Error: Error at log in: 0xa0\n\nException AttributeError: "\'LocalHSM\' object has no attribute \'p11\'" in <bound method LocalHSM.__del__ of <ipapython.dnssec.localhsm.LocalHSM object at 0x47f1090>> ignored\n'
:raiseonerr: True
:env: {'LANG': 'en_US.UTF-8', 'SHELL': '/sbin/nologin', 'KRB5CCNAME': '/tmp/ipa-dnskeysyncd.ccache', 'LOGNAME': 'ods', 'USER': 'ods', 'SOFTHSM2_CONF': '/etc/ipa/dnssec/softhsm2.conf', 'PATH': '/bin:/sbin:/usr/kerberos/bin:/usr/kerberos/sbin:/usr/bin:/usr/sbin', 'HOME': '//var/lib/softhsm'}
:cwd: None
:args: ['/usr/libexec/ipa/ipa-dnskeysync-replica']

And
backtrace:
:localhsm.py:97:__init__:Error: Error at log in: 0xa0
:
:
:Traceback (most recent call last):
:  File "/usr/libexec/ipa/ipa-dnskeysync-replica", line 171, in <module>
:    open(paths.DNSSEC_SOFTHSM_PIN).read())
:  File "/usr/lib/python2.7/site-packages/ipapython/dnssec/localhsm.py", line 97, in __init__
:    self.p11 = _ipap11helper.P11_Helper(slot, pin, library)
:Error: Error at log in: 0xa0
:
:
:Local variables in innermost frame:
:slot: 0
:self: <ipapython.dnssec.localhsm.LocalHSM object at 0x47f1090>
:library: '/usr/lib64/pkcs11/libsofthsm2.so'
:pin: 'OGIfVEsRqtgbB6vQuWMzjcCcDedA1K'


Version-Release number of selected component (if applicable):
[root@dhcp207-229 ~]# rpm -q ipa-server
ipa-server-4.2.0-8.el7.x86_64
[root@dhcp207-229 ~]# 

How reproducible:
Always

Steps to Reproduce:
1. Do ipa backup
2. ipa restore (full) from backup taken in step(1)

Actual results:
Crashes of ipa-dnskeysync-replica observed

Expected results:
No crash during ipa-restore process.

Additional info:

Comment 2 Martin Bašti 2015-09-09 15:20:44 UTC
Steps to reproduce:
1. server install
2. backup
3. server uninstall
4. server install
5. restore


Because server is installed, directory /var/lib/ipa/dnssec/tokens/ contains current tokens.

Restore adds there new tokens, but unfortunately old tokens are not removed, new tokens are just added into directory, and this cause issues with login.

Comment 3 Martin Bašti 2015-09-10 11:40:02 UTC
Upstream ticket:
https://fedorahosted.org/freeipa/ticket/5293

Comment 7 Kaleem 2015-10-01 14:08:53 UTC
Still observing the crash with ipa-4.2.0-12.el7

Please find the attached file with crash info.

Comment 8 Kaleem 2015-10-01 14:09:53 UTC
Created attachment 1079124 [details]
crash log info

Comment 9 Kaleem 2015-10-16 06:40:10 UTC
Crash not seen with latest beaker runs of b&r feature, so turning it to verified state.

snip from beaker log:
=====================

 +-----------------------------[RPMs & OS: [RedHat - x86_64]-----------------------------+
|       ipa-admintools-4.2.0-15.el7.x86_64
|       ipa-client-4.2.0-15.el7.x86_64
|       ipa-server-4.2.0-15.el7.x86_64
|       ipa-server-dns-4.2.0-15.el7.x86_64
|       ipa-tests-ipa-server-rhel72-ipa-backup-restore-ksiddiqu-20150828120910-0.noarch
|       ipa-tests-ipa-server-rhel72-shared-20150930150523-0.noarch
|       sssd-ipa-1.13.0-40.el7.x86_64
------------------------------------------------------------------------------------------

 +-----------------------------------------------------------------------------------------+
     Test:[/ipa-server/rhel72/ipa-backup-restore/root]: [ Pass(8/8): 100% ] 
 +-----------------------------------------------------------------------------------------+
:: [   PASS   ]   ipa-backup_restore startup: Initial setup
:: [   PASS   ]   TC_001 :: IPA backup restore full
:: [   PASS   ]   TC_002 :: IPA backup restore full with gpg encryption/decryption related test cases
:: [   PASS   ]   TC_003 :: Data backup/restore related test cases
:: [   PASS   ]   TC_004 :: Data backup/restore backend/instance related test cases 
:: [   PASS   ]   TC_005 :: Additional test cases
:: [   PASS   ]   TC_006 :: Data restore from full backup related test cases
:: [   PASS   ]   /ipa-server/rhel72/ipa-backup-restore/root

 +----------------------------------------------------------------------+

Comment 10 errata-xmlrpc 2015-11-19 12:06:19 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.

https://rhn.redhat.com/errata/RHBA-2015-2362.html