[ubuntu_bootstrap] Sometimes discovered slave is unavailable via SSH

[Artem Panchenko]

Sometimes discovered slave nodes are unavailable via SSH, because the daemon is stopped (see attached screenshot). I happens because SSH is restarted when network interface state is changed. Currently we have a hack in our Ubuntu bootstrap for enabling predictable interface naming (which is not fully supported by Ubuntu 14.04) - we perform `ifdown eth0` on startup and re-trigger udev events:

https://github.com/openstack/fuel-agent/commit/2f18b7596bc7da79d2f28c34f42620b2090d8a35

According to the logs it causes SSH daemon failure:

syslog:

2015-12-21T12:19:22Z notice let-rename[1074]: The old interface name is eth0
2015-12-21T12:19:22Z notice let-rename[1075]: The MAC address of the interface is 64:4d:0c:1e:26:2b
2015-12-21T12:19:22Z warning kernel: [ 10.267017] init: network-interface (eth0) pre-start process (523) killed by TERM signal
...
2015-12-21T12:19:22Z info kernel: [ 10.436180] systemd-udevd[501]: renamed network interface eth0 to enp0s3
2015-12-21T12:19:22Z notice let-rename[1195]: New interface name is enp0s3

auth.log:

2015-12-21T12:19:22Z info sshd[786]: Server listening on 0.0.0.0 port 22.
2015-12-21T12:19:22Z info sshd[786]: Server listening on :: port 22.
2015-12-21T12:19:22Z info sshd[786]: Received signal 15; terminating.

I tried to reproduce it manually on already bootstrapped node (restarted enp0s3 interface a lot of times), but with no luck - SSH daemon hasn't died. So I believe we get some kind of race condition while disabling network interface on startup. IMHO we could try to backport 'udev' from Ubuntu vivid (which seems supports predictable interface naming) and configure upstart to run 'networking' after 'udev' in order to get rid from 'let-rename'. If it doesn't work, then one more hack is needed in rc.local - check that SSH is running.

[Aleksey Zvyagintsev (azvyagintsev)]

Actually, init config of sshd contain "respawn" option.
I believe, your issue related to something other then network restart.

Please, try to reproduce issue(maybe some trace\dumps also was generated?)
(Also, i didn't find any auth logs in snapshot)

[Artem Panchenko (apanchenko-8)]

>Actually, init config of sshd contain "respawn" option.

yes it does contain "respawn" and if I kill ssh daemon manually - it's restarted. I agree that it's ridiculous that sometimes SSH goes down after network restart and upstart doesn't re-spawn it, maybe I'm missing something...

>I believe, your issue related to something other then network restart.

the only thing I can prove now is that SSH is always restarted after `ifdown`, see attached files 'screen.log' and 'dump'. Maybe it's related to bug #1446448

>Please, try to reproduce issue(maybe some trace\dumps also was generated?)

as I mentioned in description, I can't reproduce it. But it's often reproduced on CI, please contact me in IRC, I'll provide the links.

>(Also, i didn't find any auth logs in snapshot)

yes, those logs are not fetched from slaves. Attached full '/var/log' folder from the slave node.

[Albert Syriy (asyriy)]

[Artem wrote]
>"IMHO we could try to backport 'udev' from Ubuntu vivid (which seems supports predictable interface naming) and configure upstart to run 'networking' after 'udev' in order to get rid from 'let-rename' ".

The root cause of the issue is not udev rules, but interconnection between system managers Upstart and systemd-udev (Upstart-udev-bridge). The udev events (to rename interfaces) are sent too late, when all services have been started and running and when the interface eth0 is up. As the result the renaming eth0 fails. Additional investigation is required how to speed up sending udev messages from Upstart to systemd.
Ubuntu 16.x are moving to systemd manager, so the issue is going to be fixed.

Currently I can propose to add the command restarting ssh at the end of the script
"service networking restart"
or
"service ssh restart"

[Artem Panchenko (apanchenko-8)]

>The udev events (to rename interfaces) are sent too late, when all services have been started and running and when the interface eth0 is up.

yes, networking is started simultaneously with udev and it's a problem, but it could be easily fixed by patching upstart config. I just modified '/etc /init/networking.conf' and configured it to 'start on (started udev)' to fix that. However it doesn't solve interfaces naming issue, according to the logs I see that kernel (e1000 driver) sets 'eth0' up (probably due to network boot) before udev is started , so it is unable to rename it. I thought that newer udev (not only its rules, but also the code) could handle such situations and rename enabled interfaces too (there are a bunch of bugs about that in 15.04/15.10, for example bug #1473542). But maybe I'm wrong.

[Albert Syriy (asyriy)]

You are correct, udev comes when interface has been up (activated).
There is a moment at live-boot when file system has been mounted and
interfaces' config files are formed.
At that time interfaces could be renamed easily, but udev rules are called
much more later.

Don't think it's a good idea take from non-LTS distributive systemd. It's
not stable enough yet.

Albert Syriy,

Software Engineer,
Mirantis

On Tue, Dec 22, 2015 at 3:17 PM, Artem Panchenko <email address hidden>
wrote:

> >The udev events (to rename interfaces) are sent too late, when all
> services have been started and running and when the interface eth0 is
> up.
>
> yes, networking is started simultaneously with udev and it's a problem,
> but it could be easily fixed by patching upstart config. I just modified
> '/etc /init/networking.conf' and configured it to 'start on (started
> udev)' to fix that. However it doesn't solve interfaces naming issue,
> according to the logs I see that kernel (e1000 driver) sets 'eth0' up
> (probably due to network boot) before udev is started , so it is unable
> to rename it. I thought that newer udev (not only its rules, but also
> the code) could handle such situations and rename enabled interfaces too
> (there are a bunch of bugs about that in 15.04/15.10, for example bug
> #1473542). But maybe I'm wrong.
>
> --
> You received this bug notification because you are a bug assignee.
> https://bugs.launchpad.net/bugs/1528275
>
> Title:
> [ubuntu_bootstrap] Sometimes discovered slave is unavailable via SSH
>
> Status in Fuel for OpenStack:
> Confirmed
>
> Bug description:
> Sometimes discovered slave nodes are unavailable via SSH, because the
> daemon is stopped (see attached screenshot). I happens because SSH is
> restarted when network interface state is changed. Currently we have a
> hack in our Ubuntu bootstrap for enabling predictable interface naming
> (which is not fully supported by Ubuntu 14.04) - we perform `ifdown
> eth0` on startup and re-trigger udev events:
>
> https://github.com/openstack/fuel-
> agent/commit/2f18b7596bc7da79d2f28c34f42620b2090d8a35
>
> According to the logs it causes SSH daemon failure:
>
> syslog:
>
> 2015-12-21T12:19:22Z notice let-rename[1074]: The old interface name is
> eth0
> 2015-12-21T12:19:22Z notice let-rename[1075]: The MAC address of the
> interface is 64:4d:0c:1e:26:2b
> 2015-12-21T12:19:22Z warning kernel: [ 10.267017] init:
> network-interface (eth0) pre-start process (523) killed by TERM signal
> ...
> 2015-12-21T12:19:22Z info kernel: [ 10.436180] systemd-udevd[501]:
> renamed network interface eth0 to enp0s3
> 2015-12-21T12:19:22Z notice let-rename[1195]: New interface name is
> enp0s3
>
> auth.log:
>
> 2015-12-21T12:19:22Z info sshd[786]: Server listening on 0.0.0.0 port
> 22.
> 2015-12-21T12:19:22Z info sshd[786]: Server listening on :: port 22.
> 2015-12-21T12:19:22Z info sshd[786]: Received signal 15; terminating.
>
> I tried to reproduce it manually on already bootstrapped node
> (restarted enp0s3 interface a lot of times), but with no luck - SSH
> daemon hasn't died. So I believe we get some kind of race condition
> while di...

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/260553

[Albert Syriy (asyriy)]

I have built the custom ISO with the fix
http://jenkins-product.srt.mirantis.net:8080/job/custom_8.0_iso/1327/
Could you check the fix?

[Aleksey Zvyagintsev (azvyagintsev)]

I have not caught bug in ~ 6 hours run of loop-test with let-rename.
But anyway - i can't see any problem with adding Albert patch. lets add id just do be sure.

[Artem Panchenko (apanchenko-8)]

This issue can't be reproduced just by ifdown && ifup (let-rename), I tried to do that with custom auto tests as well as nodes reboot (re-bootstrap) in a loop (1000 re-tries) - no luck. So unfortunately, we can't just "check the fix".

By the way, I don't understand why we need to restart networking while SSH is down, looks like it doesn't work (see screenshot). If we are going to add more hacks to the startup scripts, I propose this command:

if ! pkill -0 sshd; then start ssh; fi

[Albert Syriy (asyriy)]

I have update the patch and start build custom ISO
http://jenkins-product.srt.mirantis.net:8080/job/custom_8.0_iso/1338/

[Albert Syriy (asyriy)]

Fix proposed, waiting for review
https://review.openstack.org/#/c/260553/3

[Artem Panchenko (apanchenko-8)]

JFYI this issue is still reproduced on CI, for example:

https://product-ci.infra.mirantis.net/job/8.0.system_test.ubuntu.thread_non_func_1/88/testReport/(root)/deploy_ha_one_controller_neutron_master_node_fail/deploy_ha_one_controller_neutron_master_node_fail/

[Artem Panchenko (apanchenko-8)]

Got this issue today on BVT for iso #378, adding 'swarm-blocker' tag

[Dmitry Pyzhov (dpyzhov)]

tech-debt tag is only for bugs that don't affect users

[Albert Syriy (asyriy)]

Still working on a fix for the bug.

According to the log there is following sequence of events:

=================
Kernel detected the network adapters:
2016-01-11T13:57:25Z info kernel: [ 4.853784] e1000 0000:02:01.0 eth0: (PCI:66MHz:32-bit) 00:50:56:9c:63:15
2016-01-11T13:57:25Z info kernel: [ 4.855246] e1000 0000:02:01.0 eth0: Intel(R) PRO/1000 Network Connection
2016-01-11T13:57:25Z info kernel: [ 5.226084] e1000 0000:02:02.0 eth1: (PCI:66MHz:32-bit) 00:50:56:9c:79:6e
2016-01-11T13:57:25Z info kernel: [ 5.227567] e1000 0000:02:02.0 eth1: Intel(R) PRO/1000 Network Connection
...
Live boot script from initrd.img (9990-select-eth-device.sh and 9990-networking.sh ) called CLI following commands
modprobe -q af_packet
ipconfig -t "$ETHDEV_TIMEOUT" ${interface} | tee /netboot-${interface}.config
to bring eth0 up and start DHCP
Have the following messages in the log:

Systemd-udevd started:
2016-01-11T13:57:25Z info kernel: [ 3.983241] systemd-udevd[94]: starting version 204
...
2016-01-11T13:57:25Z info kernel: [ 5.439577] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
2016-01-11T13:57:25Z info kernel: [ 5.441498] e1000: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
2016-01-11T13:57:25Z info kernel: [ 5.445117] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
...
Download and mount rooot.squashfs image, change mount point to the root.squashfs image
2016-01-11T13:57:25Z info kernel: [ 8.536898] squashfs: version 4.0 (2009/01/31) Phillip Lougher
...
Start Init and it issued the startup event.
2016-01-11T13:57:25Z debug kernel: [ 8.939757] init: event_new: Pending startup event
...
The StartUP job mountall, virtualfs, udev are started.
2016-01-11T13:57:25Z info kernel: [ 8.944451] init: mountall state changed from waiting to starting
...
2016-01-11T13:57:25Z info kernel: [ 15.101632] init: udev goal changed from stop to start
2016-01-11T13:57:25Z info kernel: [ 15.106737] init: udev state changed from waiting to starting
...
2016-01-11T13:57:25Z info kernel: [ 15.558721] init: procps (virtual-filesystems) state changed from post-start to running
2016-01-11T13:57:25Z info kernel: [ 15.568788] IPv6: ADDRCONF(NETDEV_UP): eth1: link is not ready
...
Upstart-udev-bridge started prior the udev

2016-01-11T13:57:25Z info kernel: [ 15.638075] init: upstart-udev-bridge state changed from starting to security
2016-01-11T13:57:25Z info kernel: [ 15.642746] init: upstart-udev-bridge state changed from security to pre-start
2016-01-11T13:57:25Z info kernel: [ 15.646695] init: upstart-udev-bridge state changed from pre-start to spawned
2016-01-11T13:57:25Z info kernel: [ 15.656621] init: upstart-udev-bridge main process (436)
...
2016-01-11T13:57:25Z info kernel: [ 16.411979] init: udev state changed from starting to security
2016-01-11T13:57:25Z info kernel: [ 16.414705] init: udev state changed from security to pre-start
2016-01-11T13:57:25Z info kernel: [ 16.418711] init: udev state changed from pre-start to spawned
2016-01-11T13:57:25Z info kernel: [ 16.434817] init: udev main process (448)
... (udev respain) ...
2016-01-11T13:57:25Z info kernel: [ 17.749879] init: ud...

[Alexandr Kostrikov (akostrikov-mirantis)]

We have a lot of reproduces today, setting it to critical

[Alexei Sheplyakov (asheplyakov)]

The correct way to solve the problem is to avoid the race, trying to win it is deemed to fail.
Please rename the interfaces in early userspace (initramfs), make sure the udev rule which enables predictable interfaces naming is included into live-boot initramfs.

[Igor Marnat (imarnat)]

Potential fix is being tested: https://review.openstack.org/#/c/267667/4

[OpenStack Infra (hudson-openstack)]

Change abandoned by Albert Syriy (<email address hidden>) on branch: master
Review: https://review.openstack.org/260553
Reason: Not need any more, there is a fix

[Albert Syriy (asyriy)]

The fix has been committed for a review.
The custom ISO has been built
http://jenkins-product.srt.mirantis.net:8080/job/custom_8.0_iso/1681/

Albert Syriy,

Software Engineer,
Mirantis

On Mon, Jan 18, 2016 at 4:42 PM, Igor Marnat <email address hidden> wrote:

> Potential fix is being tested: https://review.openstack.org/#/c/267667/4
>
> --
> You received this bug notification because you are a bug assignee.
> https://bugs.launchpad.net/bugs/1528275
>
> Title:
> [ubuntu_bootstrap] Sometimes discovered slave is unavailable via SSH
>
> Status in Fuel for OpenStack:
> In Progress
>
> Bug description:
> Sometimes discovered slave nodes are unavailable via SSH, because the
> daemon is stopped (see attached screenshot). I happens because SSH is
> restarted when network interface state is changed. Currently we have a
> hack in our Ubuntu bootstrap for enabling predictable interface naming
> (which is not fully supported by Ubuntu 14.04) - we perform `ifdown
> eth0` on startup and re-trigger udev events:
>
> https://github.com/openstack/fuel-
> agent/commit/2f18b7596bc7da79d2f28c34f42620b2090d8a35
>
> According to the logs it causes SSH daemon failure:
>
> syslog:
>
> 2015-12-21T12:19:22Z notice let-rename[1074]: The old interface name is
> eth0
> 2015-12-21T12:19:22Z notice let-rename[1075]: The MAC address of the
> interface is 64:4d:0c:1e:26:2b
> 2015-12-21T12:19:22Z warning kernel: [ 10.267017] init:
> network-interface (eth0) pre-start process (523) killed by TERM signal
> ...
> 2015-12-21T12:19:22Z info kernel: [ 10.436180] systemd-udevd[501]:
> renamed network interface eth0 to enp0s3
> 2015-12-21T12:19:22Z notice let-rename[1195]: New interface name is
> enp0s3
>
> auth.log:
>
> 2015-12-21T12:19:22Z info sshd[786]: Server listening on 0.0.0.0 port
> 22.
> 2015-12-21T12:19:22Z info sshd[786]: Server listening on :: port 22.
> 2015-12-21T12:19:22Z info sshd[786]: Received signal 15; terminating.
>
> I tried to reproduce it manually on already bootstrapped node
> (restarted enp0s3 interface a lot of times), but with no luck - SSH
> daemon hasn't died. So I believe we get some kind of race condition
> while disabling network interface on startup. IMHO we could try to
> backport 'udev' from Ubuntu vivid (which seems supports predictable
> interface naming) and configure upstart to run 'networking' after
> 'udev' in order to get rid from 'let-rename'. If it doesn't work, then
> one more hack is needed in rc.local - check that SSH is running.
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/fuel/+bug/1528275/+subscriptions
>

[Albert Syriy (asyriy)]

The fix has been committed for review
https://review.fuel-infra.org/#/c/16276/
https://review.openstack.org/#/c/270008/

The patch has been checked on the lab (successfully)

[Artem Panchenko (apanchenko-8)]

@bogdando,

I wonder why is this created on 2015-12-21 *Fuel* bug is duplicate of *MOS* bug #1529631 which was created a week later (2015-12-28)?

[Fuel Devops McRobotson (fuel-devops-robot)]

Reviewed: https://review.fuel-infra.org/16276
Submitter: Pkgs Jenkins <email address hidden>
Branch: master

Commit: f2f0951cd47cbfa64630b595e014ac48ece7a484
Author: Albert Syriy <email address hidden>
Date: Thu Jan 21 16:15:28 2016

Fix enabling udev to rename the network interface on Ubuntu bootstrap

The fix enabling to use predictable network interface naming on
bootstrap. The live-boot was patched to enable using predictable
interface names on bootstrap. The Get_ethernet_interfaces
function was designed to collect ethernet interfaces names.
Additional udev 75-net-description.rules rule is copied during
the installation into bootstrap, enabling renaming network
interfaces at the very beginning.

Change-Id: I7ddc1ac41813747ae0285900a3540f39b89161cb
Closes-Bug: #1528275, #1529631

[Fuel Devops McRobotson (fuel-devops-robot)]

Fix proposed to branch: 8.0
Change author: Albert Syriy <email address hidden>
Review: https://review.fuel-infra.org/16365

[Fuel Devops McRobotson (fuel-devops-robot)]

Reviewed: https://review.fuel-infra.org/16365
Submitter: Pkgs Jenkins <email address hidden>
Branch: 8.0

Commit: f6f52a4ebc4c40e63c0b21983ca5477758aeddd1
Author: Albert Syriy <email address hidden>
Date: Thu Jan 21 18:51:31 2016

Fix enabling udev to rename the network interface on Ubuntu bootstrap

The fix enabling to use predictable network interface naming on
bootstrap. The live-boot was patched to enable using predictable
interface names on bootstrap. The Get_ethernet_interfaces
function was designed to collect ethernet interfaces names.
Additional udev 75-net-description.rules rule is copied during
the installation into bootstrap, enabling renaming network
interfaces at the very beginning.

Change-Id: I7ddc1ac41813747ae0285900a3540f39b89161cb
Closes-Bug: #1528275, #1529631
(cherry picked from commit f2f0951cd47cbfa64630b595e014ac48ece7a484)

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/270008
Committed: https://git.openstack.org/cgit/openstack/fuel-agent/commit/?id=469b68b83be9dd2d5f3bf0b31fe3e63d875daa34
Submitter: Jenkins
Branch: master

commit 469b68b83be9dd2d5f3bf0b31fe3e63d875daa34
Author: Albert <email address hidden>
Date: Wed Jan 20 07:26:36 2016 +0200

    Revert the work-around for renaming PXE interface on Ubuntu bootstrap

    The fix for the renaming interface used on PXE boot of Ubuntu
    bootstrap is in the live-boot_4.0.2-1~u14.04+mos2 package.
    We don't need this work-around any more. Related to the
    LP #1529631 and LP #1528275.

    Depends-On: I7ddc1ac41813747ae0285900a3540f39b89161cb
    Change-Id: I4eaca76175e6df308b819c7f06ff057318f3115b
    Related-Bug: #1529631
    Related-Bug: #1528275

[OpenStack Infra (hudson-openstack)]

Related fix proposed to branch: stable/8.0
Review: https://review.openstack.org/271748

[Fuel Devops McRobotson (fuel-devops-robot)]

Fix proposed to branch: 9.0
Change author: Albert Syriy <email address hidden>
Review: https://review.fuel-infra.org/16418

[Fuel Devops McRobotson (fuel-devops-robot)]

Reviewed: https://review.fuel-infra.org/16418
Submitter: Pkgs Jenkins <email address hidden>
Branch: 9.0

Commit: 4f325c3b28f5364768ea63b47fa9c9b335d0f4d8
Author: Albert Syriy <email address hidden>
Date: Mon Jan 25 11:13:53 2016

Fix enabling udev to rename the network interface on Ubuntu bootstrap

The fix enabling to use predictable network interface naming on
bootstrap. The live-boot was patched to enable using predictable
interface names on bootstrap. The Get_ethernet_interfaces
function was designed to collect ethernet interfaces names.
Additional udev 75-net-description.rules rule is copied during
the installation into bootstrap, enabling renaming network
interfaces at the very beginning.

Change-Id: I7ddc1ac41813747ae0285900a3540f39b89161cb
Closes-Bug: #1528275, #1529631
(cherry picked from commit f2f0951cd47cbfa64630b595e014ac48ece7a484)

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/271748
Committed: https://git.openstack.org/cgit/openstack/fuel-agent/commit/?id=e869072139670bb8bbfde00ef04dec3d189f5927
Submitter: Jenkins
Branch: stable/8.0

commit e869072139670bb8bbfde00ef04dec3d189f5927
Author: Albert <email address hidden>
Date: Wed Jan 20 07:26:36 2016 +0200

    Revert the work-around for renaming PXE interface on Ubuntu bootstrap

    The fix for the renaming interface used on PXE boot of Ubuntu
    bootstrap is in the live-boot_4.0.2-1~u14.04+mos2 package.
    We don't need this work-around any more. Related to the
    LP #1529631 and LP #1528275.

    Depends-On: I7ddc1ac41813747ae0285900a3540f39b89161cb
    Change-Id: I4eaca76175e6df308b819c7f06ff057318f3115b
    Related-Bug: #1529631
    Related-Bug: #1528275
    (cherry picked from commit 469b68b83be9dd2d5f3bf0b31fe3e63d875daa34)

[Fuel Devops McRobotson (fuel-devops-robot)]

Fix proposed to branch: 7.0
Change author: Albert Syriy <email address hidden>
Review: https://review.fuel-infra.org/23751