Bug 952801 - Anaconda doesn't wait for NetworkManager before giving up on VNC install (Not asking for VNC because we don't have a network)
Summary: Anaconda doesn't wait for NetworkManager before giving up on VNC install (Not...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: anaconda
Version: 19
Hardware: Unspecified
OS: Unspecified
unspecified
medium
Target Milestone: ---
Assignee: Radek Vykydal
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2013-04-16 18:11 UTC by Gustavo Luiz Duarte
Modified: 2013-05-29 13:56 UTC (History)
7 users (show)

Fixed In Version: anaconda-19.24-1.fc19
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2013-05-22 03:17:35 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
anaconda.log (2.59 KB, text/plain)
2013-05-23 18:32 UTC, Mark Hamzy
no flags Details
syslog (66.76 KB, text/plain)
2013-05-23 18:32 UTC, Mark Hamzy
no flags Details

Description Gustavo Luiz Duarte 2013-04-16 18:11:44 UTC
Description of problem:
I have a ppc64 machine with 4 network interfaces and no graphics card (serial console only). Anaconda gets to the point of deciding on doing VNC install before NetworkManager has a chance to finish the network setup. Then I get the following message from Anaconda:

17:48:50 Not asking for VNC because we don't have a network
17:48:51 X startup failed, falling back to text mode

A few moments later I can go to the Anaconda shell (ctrl-b 2) then run ifconfig and see that eth0 has been assigned an IP address.

More info:
[anaconda root@localhost ~]# grep eth0 /tmp/ifcfg.log                              
17:48:58,957 DEBUG ifcfg: /etc/sysconfig/network-scripts/ifcfg-eth0:
NAME=eth0

Note that the time in ifcfg.log is a few seconds later then the Anaconda message stating "we don't have a network".


Version-Release number of selected component (if applicable):
anaconda-19.17-1.fc19.ppc64

How reproducible:
Always

Steps to Reproduce:
1. Boot Fedora 19 pre-alpha
2.
3.
  
Actual results:
Anaconda falls back to text mode.

Expected results:
Anaconda should ask if I want to do a VNC install since I do have network connection.

Additional info:

Comment 1 Gustavo Luiz Duarte 2013-04-16 18:20:39 UTC
It is interesting that if I enter "linux inst.vnc" to the boot command line I get the following sequence of messages from Anaconda:

18:17:42 Not asking for VNC because we don't have a network
18:17:42 Starting VNC...
18:17:48 The VNC server is now running.

Then I can proceed with VNC installation.

Comment 2 Radek Vykydal 2013-04-25 07:30:51 UTC
Thank you for your report.

Patch sent for review, you can check if it works for you using updates image by adding this to boot options:

updates=http://rvykydal.fedorapeople.org/updates.vnc.connecting.19.17.img

for the version 19.17 from the Description

or

updates=http://rvykydal.fedorapeople.org/updates.vnc.connecting.f19alpha.img

for F19 Alpha

Comment 3 Fedora Update System 2013-04-30 12:22:39 UTC
anaconda-19.23-1.fc19 has been submitted as an update for Fedora 19.
https://admin.fedoraproject.org/updates/anaconda-19.23-1.fc19

Comment 4 Fedora Update System 2013-04-30 20:02:34 UTC
Package anaconda-19.23-1.fc19:
* should fix your issue,
* was pushed to the Fedora 19 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing anaconda-19.23-1.fc19'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2013-7049/anaconda-19.23-1.fc19
then log in and leave karma (feedback).

Comment 5 Fedora Update System 2013-05-03 21:05:45 UTC
anaconda-19.24-1.fc19 has been submitted as an update for Fedora 19.
https://admin.fedoraproject.org/updates/anaconda-19.24-1.fc19

Comment 6 Mark Hamzy 2013-05-13 18:18:17 UTC
Radek,

What is the git commit id for this?

Is this the patch?

https://lists.fedorahosted.org/pipermail/anaconda-patches/2013-April/003906.html

I am still seeing this:

Starting installer, one moment...
anaconda 19.25-1 for Fedora 19 (pre-release) started.
15:36:35 Not asking for VNC because we don't have a network
15:36:35 X startup failed, falling back to text mode

Comment 7 Radek Vykydal 2013-05-14 11:03:46 UTC
(In reply to comment #6)
> Radek,
> 
> What is the git commit id for this?
> 

commit 9a0542611b2f03434a9067b76e54bf6162e971ba, the patch should be there (in 19,25).

> Is this the patch?
> 
> https://lists.fedorahosted.org/pipermail/anaconda-patches/2013-April/003906.
> html
> 

Yes.

> I am still seeing this:
> 
> Starting installer, one moment...
> anaconda 19.25-1 for Fedora 19 (pre-release) started.
> 15:36:35 Not asking for VNC because we don't have a network
> 15:36:35 X startup failed, falling back to text mode

Hm, you might be seeing another race (checking connection for vnc even before NM gets into connecting state). Could you please attach anaconda.log and syslog from your reproducer? Thanks

Comment 8 Fedora Update System 2013-05-22 03:17:35 UTC
anaconda-19.24-1.fc19, python-blivet-0.12-1.fc19 has been pushed to the Fedora 19 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 9 Mark Hamzy 2013-05-23 18:32:02 UTC
Created attachment 752315 [details]
anaconda.log

Comment 10 Mark Hamzy 2013-05-23 18:32:51 UTC
Created attachment 752316 [details]
syslog

Comment 11 Mark Hamzy 2013-05-23 18:34:05 UTC
Radek,

I came across this again:

anaconda 19.28-1 for Fedora 19 (pre-release) started.
18:14:37 Not asking for VNC because we don't have a network
18:14:37 X startup failed, falling back to text mode

Do the attached logs help?

Comment 12 Radek Vykydal 2013-05-27 12:31:37 UTC
Thanks for the logs, it seems you might be hitting a race caused by wrong order of conditions in patch from comment #6

if not nm_is_connected() and not nm_is_connecting():
    stdoutLog.warning("Not asking for VNC because we don't have a network")

from the logs:

18:14:37,312      INFO NetworkManager: <info> Activation (eth1) successful, device activated.
18:14:37,313      INFO NetworkManager: <info> (eth0): device state change: secondaries -> activated (reason 'none') [90 100 0]
18:14:37,331      INFO NetworkManager: <info> Activation (eth0) successful, device activated.
18:14:37,332      INFO NetworkManager: <info> Activation (eth1) Stage 5 of 5 (IPv6 Commit) scheduled...
18:14:37,333  WARN anaconda.stdout: Not asking for VNC because we don't have a network

we can see that the condition is tested just about the time the devices become activated. This is most probably the point where NM moves from state connecting to connected, so what might happen here is: 

- NM is in connecting state
- nm_is_connected() is checked and fails
- NM goes to connected state
- nm_is_connecting() is checked and fails

If the conditions were swapped this race should not happen (or we could add "atomic" check for both connecting and connected states in nm.py).

I'll send a patch swapping the conditions and let's hope my theory was right.

Here is updates image with fix for 19.29:
http://rvykydal.fedorapeople.org/updates.vncrace.img
but I suppose it is very difficult to reproduce the race condition and therefore almost impossible to confirm reliably that the patch actually fixes it.

Comment 13 Mark Hamzy 2013-05-28 19:26:34 UTC
I agree that it would be difficult to reproduce the race condition.  Should I reopen this bug?

Comment 14 Radek Vykydal 2013-05-29 12:07:34 UTC
Mark, I pushed the patch from comment #12 both to master and f19-branch, it should go to builds following anaconda-19.30-1 build. I wouldn't reopen the BZ, if you really care open a new one but it would be very difficult to reproduce/verify so I'd just consider the issue fixed, waiting whether we hit the same issue in future.

Comment 15 Mark Hamzy 2013-05-29 13:56:28 UTC
Awesome, thanks!


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