reapplying stx-openstack application failed on swacted host

[Peng Peng]

Brief Description
-----------------
After host swact success, tried to reapply stx-openstack, but the status stuck at "applying application manifest", and eventually apply-failed by operation aborted.

Severity
--------
Major

Steps to Reproduce
------------------
host-swact
application-apply
application-list

TC-name: z_containers/test_openstack_services.py::test_reapply_stx_openstack_no_change[controller-1]

Expected Behavior
------------------
reapply success

Actual Behavior
----------------
reapply failed

Reproducibility
---------------
Seen once

System Configuration
--------------------
Multi-node system

Lab-name: WCP_63-66

Branch/Pull Time/Commit
-----------------------
stx master as of 20190718T013000Z

Last Pass
---------
2019-05-29_17-05-57

Timestamp/Logs
--------------
[2019-07-18 11:30:42,593] 301 DEBUG MainThread ssh.send :: Send 'system --os-username 'admin' --os-password 'Li69nux*' --os-project-name admin --os-auth-url http://192.168.204.2:5000/v3 --os-user-domain-name Default --os-project-domain-name Default --os-endpoint-type internalURL --os-region-name RegionOne host-swact controller-0'

[2019-07-18 11:31:59,398] 301 DEBUG MainThread ssh.send :: Send 'system --os-username 'admin' --os-password 'Li69nux*' --os-project-name admin --os-auth-url http://192.168.204.2:5000/v3 --os-user-domain-name Default --os-project-domain-name Default --os-endpoint-type internalURL --os-region-name RegionOne application-list'
[2019-07-18 11:32:00,986] 423 DEBUG MainThread ssh.expect :: Output:
+---------------------+--------------------------------+-------------------------------+--------------------+---------------+------------------------------------------+
| application | version | manifest name | manifest file | status | progress |
+---------------------+--------------------------------+-------------------------------+--------------------+---------------+------------------------------------------+
| hello-kitty | 1.0 | hello-kitty | manifest.yaml | remove-failed | operation aborted, check logs for detail |
| platform-integ-apps | 1.0-7 | platform-integration-manifest | manifest.yaml | applied | completed |
| stx-openstack | 1.0-17-centos-stable-versioned | armada-manifest | stx-openstack.yaml | applied | completed |

[2019-07-18 11:36:12,843] 301 DEBUG MainThread ssh.send :: Send 'system --os-username 'admin' --os-password 'Li69nux*' --os-project-name admin --os-auth-url http://192.168.204.2:5000/v3 --os-user-domain-name Default --os-project-domain-name Default --os-endpoint-type internalURL --os-region-name RegionOne application-apply stx-openstack'
[2019-07-18 11:36:14,493] 423 DEBUG MainThread ssh.expect :: Output:
+---------------+----------------------------------+
| Property | Value |
+---------------+----------------------------------+
| active | True |
| app_version | 1.0-17-centos-stable-versioned |
| created_at | 2019-07-18T07:44:44.655135+00:00 |
| manifest_file | stx-openstack.yaml |
| manifest_name | armada-manifest |
| name | stx-openstack |
| progress | None |
| status | applying |
| updated_at | 2019-07-18T11:29:55.319384+00:00 |
+---------------+----------------------------------+
Please use 'system application-list' or 'system application-show stx-openstack' to view the current progress.
controller-1:~$

[2019-07-18 11:41:05,280] 301 DEBUG MainThread ssh.send :: Send 'system --os-username 'admin' --os-password 'Li69nux*' --os-project-name admin --os-auth-url http://192.168.204.2:5000/v3 --os-user-domain-name Default --os-project-domain-name Default --os-endpoint-type internalURL --os-region-name RegionOne application-list'
[2019-07-18 11:41:06,799] 423 DEBUG MainThread ssh.expect :: Output:
+---------------------+--------------------------------+-------------------------------+--------------------+---------------+------------------------------------------+
| application | version | manifest name | manifest file | status | progress |
+---------------------+--------------------------------+-------------------------------+--------------------+---------------+------------------------------------------+
| hello-kitty | 1.0 | hello-kitty | manifest.yaml | remove-failed | operation aborted, check logs for detail |
| platform-integ-apps | 1.0-7 | platform-integration-manifest | manifest.yaml | applied | completed |
| stx-openstack | 1.0-17-centos-stable-versioned | armada-manifest | stx-openstack.yaml | applying | applying application manifest |

[2019-07-18 11:41:42,330] 301 DEBUG MainThread ssh.send :: Send 'system --os-username 'admin' --os-password 'Li69nux*' --os-project-name admin --os-auth-url http://192.168.204.2:5000/v3 --os-user-domain-name Default --os-project-domain-name Default --os-endpoint-type internalURL --os-region-name RegionOne application-list'
[2019-07-18 11:41:43,809] 423 DEBUG MainThread ssh.expect :: Output:
+---------------------+------------------------------+-------------------------------+--------------------+---------------+------------------------------------------+
| application | version | manifest name | manifest file | status | progress |
+---------------------+------------------------------+-------------------------------+--------------------+---------------+------------------------------------------+
| hello-kitty | 1.0 | hello-kitty | manifest.yaml | remove-failed | operation aborted, check logs for detail |
| platform-integ-apps | 1.0-7 | platform-integration-manifest | manifest.yaml | applied | completed |
| stx-openstack | 1.0-17-centos-stable- | armada-manifest | stx-openstack.yaml | apply-failed | operation aborted, check logs for detail |
| | versioned | | | | |

Test Activity
-------------
Sanity

[Yang Liu (yliu12)]

Just a note that 'helm list' cmd was hanging when this issue was seen.

[Ghada Khalil (gkhalil)]

On SWACT, the TCP connections will timeout after 30 seconds and then get re-established as per the following review which merged on 2019-07-15: https://review.opendev.org/#/c/670822/

How long did the TC wait after the swact before re-applying stx-openstack?

[Peng Peng (ppeng)]

wait for 5-6 mins

11:30 host-swact controller-0
11:31 controller-1 Login successful
11:36 application-apply stx-openstack
11:41 apply-failed

[Ghada Khalil (gkhalil)]

Marking as stx.2.0 given that the TCP connections should have been re-established given the 5-6min wait.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.opendev.org/672741

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.opendev.org/672742

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/672741
Committed: https://git.openstack.org/cgit/starlingx/config/commit/?id=ae145b78f8b8891ac718fa2a4ea4b5c5a510c306
Submitter: Zuul
Branch: master

commit ae145b78f8b8891ac718fa2a4ea4b5c5a510c306
Author: Bart Wensley <email address hidden>
Date: Wed Jul 24 14:47:56 2019 -0500

    Revert "Revert "Changing tiller pod networking settings to improve swact time""

    This reverts commit a5c236dc522c050b036e638955c03074a2963996.

    It was thought that setting the TCP timeouts for the cluster
    network was enough to address the issues with the helm commands
    hanging after a controller swact. This is not the case. In
    particular, swacting away from the controller with the
    tiller-deploy pod seems to cause tcp connection from that pod to
    the kube-apiserver to hang. Putting the tiller-deploy pod back on
    the host network "fixes" the issue.

    Change-Id: I8f37530e1f615afcffcf6cb1d629518436c99cb9
    Related-Bug: 1817941
    Partial-Bug: 1837055
    Signed-off-by: Bart Wensley <email address hidden>

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/672742
Committed: https://git.openstack.org/cgit/starlingx/ansible-playbooks/commit/?id=5a1fe1616e1c541a4cdd076b672f217c22d5c843
Submitter: Zuul
Branch: master

commit 5a1fe1616e1c541a4cdd076b672f217c22d5c843
Author: Bart Wensley <email address hidden>
Date: Wed Jul 24 14:41:57 2019 -0500

    Revert "Revert "Changing tiller pod networking settings to improve swact time""

    This reverts commit fe10dcbfed9fd4a6b0e4494cd6d414bf78f03bab.

    It was thought that setting the TCP timeouts for the cluster
    network was enough to address the issues with the helm commands
    hanging after a controller swact. This is not the case. In
    particular, swacting away from the controller with the
    tiller-deploy pod seems to cause tcp connection from that pod to
    the kube-apiserver to hang. Putting the tiller-deploy pod back on
    the host network "fixes" the issue.

    Change-Id: I89c4db6dc063f238c70fad4e913577046e5452f5
    Related-Bug: 1817941
    Partial-Bug: 1837055
    Signed-off-by: Bart Wensley <email address hidden>

[Bart Wensley (bartwensley)]

The issue should be fixed now, but I am assigning it to Matt in case he has time to look for the root cause of the issue.

[Frank Miller (sensfan22)]

Based on Bart's change and analysis that the issue is now fixed, lowering priority of this LP and removing the stx.2.0 tag. It would be good to identify root cause eventually so adding an stx.3.0 tag for now.

[Matt Peters (mpeters-wrs)]

Further details of the investigation as to why changing the TCP keepalive parameters of the container was not sufficient.

When the cluster networking is used, and a swact occurs, the TCP connection to the kube-apiserver remains active because the NATed connection is not able to route the packets to the new kube-apiserver endpoint on the other controller. The socket is therefore open, but not able to communicate with the far-end, which means the socket must timeout before being cleaned up. With host networking, the packets are routed to the new destination which results in an immediate TCP reset being sent which closes the connection immediately.

The TCP keepalive timer for the tiller connection to the kube-apiserver socket is 30s, combined with the 5 probes for a total of 2.5mins. Therefore, the system settings are not being used, therefore the client side of the connection would not close the connection faster than the options set on the socket. However, it is still taking 15mins to close the connection which is based on the failed retransmit timeout that is configured by the system setting of net.ipv4.tcp_retries2=15. This timer will be activated if a request is made on the socket, overriding the keepalive timer.
Therefore, if no request is made for 2.5mins, the request will be complete successfully since the connection would have been cleaned up by the keepalive timeout. If a request is made within that 2.5mins window, the connection will remain active until the tcp_restries2 timeout.

The kube-apiserver TCP keepalive timer is set to 300s with 5 probes, so it will not be able to detect the failed connection for 15mins.

Based on the above information, it is recommended to keep the hostNetwork configuration option for the Tiller Pod since it provides the fastest socket cleanup time, re-enabling the connectivity.

[Peng Peng (ppeng)]

The issue was not reproduced recently.