Bug 1245990

Summary: iSCSI iBFT installation gets stuck on "Performing post-installation setup tasks"
Product: Red Hat Enterprise Linux 7 Reporter: Bruno Goncalves <bgoncalv>
Component: anacondaAssignee: Anaconda Maintenance Team <anaconda-maint-list>
Status: CLOSED NEXTRELEASE QA Contact: Release Test Team <release-test-team-automation>
Severity: medium Docs Contact:
Priority: medium    
Version: 7.2CC: bgoncalv, cleech, mhoyer, rvykydal
Target Milestone: rcKeywords: Regression, TestBlocker
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-08-26 14:02:27 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:
Bug Depends On:    
Bug Blocks: 1077291    

Description Bruno Goncalves 2015-07-23 09:14:13 UTC 
Description of problem:
Trying to provision a server with iBFT it gets stuck on "Performing post-installation setup tasks"

Version-Release number of selected component (if applicable):
anaconda 21.48.22.21-1
dracut-033-284.el7


How reproducible:
Seems very often on specific server

Steps to Reproduce:
1.Start RHEL-7.2 provision
2.installation will not complete
3.

Actual results:
It seems there is some connection error at post-installation script:

03:25:32,705 ERR NetworkManager: <error> [1437621932.705391] [devices/nm-device.c:2590] activation_source_schedule(): (ibft0): activation stage already scheduled
03:25:32,706 ERR NetworkManager: <error> [1437621932.705985] [devices/nm-device.c:2590] activation_source_schedule(): (enp4s0f0): activation stage already scheduled
03:27:02,975 ERR NetworkManager: <error> [1437622022.975837] [devices/nm-device.c:2590] activation_source_schedule(): (ibft0): activation stage already scheduled
03:27:02,976 ERR NetworkManager: <error> [1437622022.976061] [devices/nm-device.c:2590] activation_source_schedule(): (enp4s0f0): activation stage already scheduled
03:29:56,769 ERR kernel:[  834.169549]  connection1:0: ping timeout of 5 secs expired, recv timeout 5, last rx 4295483680, last ping 4295488688, now 4295493696
03:29:56,769 INFO kernel:[  834.169595]  connection1:0: detected conn error (1022)
03:29:57,102 WARNING iscsid: Kernel reported iSCSI connection 1:0 error (1022 - Invalid or unknown error code) state (3)
03:30:38,108 WARNING iscsid: connection1:0 is operational after recovery (2 attempts)
Comment 11 Radek Vykydal 2015-07-23 10:23:10 UTC 
Could you please try to reproduce with this updates image which turns NM debug logging on and attach syslog?

https://rvykydal.fedorapeople.org/updates.nmdebug.img
Comment 14 Radek Vykydal 2015-08-12 07:54:31 UTC 
If it is really the same issue as bug 1245463, it could be worth trying with some newer compose (eg http://download.englab.brq.redhat.com/nightly/RHEL-7.2-20150810.n.0/) with newer NetworkManager build with a MTU fix (https://brewweb.devel.redhat.com/buildinfo?buildID=450625) which could perhaps address bug 1245463.

Also, we might want to ask iscsi people what problem this error messages could indicate:

09:11:56,939 ERR kernel:[  400.496413]  connection1:0: ping timeout of 5 secs expired, recv timeout 5, last rx 4295049859, last ping 4295054860, now 4295059872
09:11:56,939 INFO kernel:[  400.496462]  connection1:0: detected conn error (1022)
09:11:57,199 WARNING iscsid: Kernel reported iSCSI connection 1:0 error (1022 - Invalid or unknown error code) state (3)
09:12:13,201 WARNING iscsid: connection1:0 is operational after recovery (1 attempts)
Comment 15 Radek Vykydal 2015-08-12 07:58:31 UTC 
> Also, we might want to ask iscsi people what problem this error messages
> could indicate:
> 
> 09:11:56,939 ERR kernel:[  400.496413]  connection1:0: ping timeout of 5
> secs expired, recv timeout 5, last rx 4295049859, last ping 4295054860, now
> 4295059872
> 09:11:56,939 INFO kernel:[  400.496462]  connection1:0: detected conn error
> (1022)
> 09:11:57,199 WARNING iscsid: Kernel reported iSCSI connection 1:0 error
> (1022 - Invalid or unknown error code) state (3)
> 09:12:13,201 WARNING iscsid: connection1:0 is operational after recovery (1
> attempts)

Chris, does it give any hint of where the problem could be?

The whole syslog comes from failing case of comment #12:
beaker-archive.app.eng.bos.redhat.com/beaker-logs/2015/07/10241/1024113/2100376/sys.log
Comment 16 Martin Hoyer 2015-08-12 11:54:02 UTC 
All installations of RHEL-7.2, including older versions which previously got stuck, are now successful, although we are not aware of any change.
Comment 17 Martin Hoyer 2015-08-13 11:01:42 UTC 
We are not able to reproduce it on RHEL-7.2 however problem still persist when RHEL-7.1 is used
Comment 19 David Cantrell 2015-08-26 14:02:27 UTC 
Closing this as NEXTRELEASE per comment #18.  If this problem reappears, please reopen the bug and attach new log files and steps to reproduce the problem.