Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1532817

Summary:

[free-stg] es pod not found during v3.7 logging upgrade

Product:

OpenShift Container Platform

Reporter:

Justin Pierce <jupierce>

Component:

Installer

Assignee:

ewolinet

Status:

CLOSED CURRENTRELEASE

QA Contact:

Anping Li <anli>

Severity:

unspecified

Docs Contact:

Priority:

unspecified

Version:

3.7.1

CC:

anli, aos-bugs, jialiu, jokerman, jupierce, mmccomas, pportant, sdodson, vlaad

Target Milestone:

---

Keywords:

NeedsTestCase

Target Release:

3.7.z

Hardware:

Unspecified

OS:

Unspecified

Whiteboard:

Fixed In Version:

Doc Type:

No Doc Update

Doc Text:

undefined

Story Points:

---

Clone Of:

Environment:

Last Closed:

2018-10-08 10:14:24 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:

1555367

Bug Blocks:

Attachments:

Description	Flags
Verbose log output	none

Description Justin Pierce 2018-01-09 20:40:02 UTC

Created attachment 1379235 [details]
Verbose log output

Description of problem:
Upgrading from v3.7.9 -> v3.7.22

Openshift-ansible logging upgrade playbook repeatedly report: Error from server (NotFound): pods "logging-es-data-master-szybvfio-8-mbnkv" not found

Including verbose log output as attachment.

The pod listed does not exist.


[root@free-stg-master-03fb6 ~]# oc get pods
NAME                                      READY     STATUS    RESTARTS   AGE
logging-curator-9-jcmb6                   1/1       Running   0          2h
logging-es-data-master-dm4qr1as-9-m8lh5   2/2       Running   0          2h
logging-es-data-master-qhgbgiw5-9-69p2l   2/2       Running   0          2h
logging-es-data-master-szybvfio-9-kxt9t   2/2       Running   0          2h
logging-fluentd-9dfcg                     1/1       Running   0          2h
logging-fluentd-fdbkq                     1/1       Running   0          2h
logging-fluentd-jggzf                     1/1       Running   0          2h
logging-fluentd-jvglk                     1/1       Running   0          2h
logging-fluentd-kqvtq                     1/1       Running   0          2h
logging-fluentd-x5p9m                     1/1       Running   0          2h
logging-fluentd-zhxpz                     1/1       Running   0          2h
logging-kibana-11-gshgz                   2/2       Running   0          2h
[root@free-stg-master-03fb6 ~]# oc get pod logging-es-data-master-szybvfio-8-mbnkv
Error from server (NotFound): pods "logging-es-data-master-szybvfio-8-mbnkv" not found

Comment 2 ewolinet 2018-01-09 21:26:07 UTC

https://github.com/openshift/openshift-ansible/pull/6602

Comment 4 Justin Pierce 2018-01-12 13:56:19 UTC

A new build of 3.7 which should contain this fix (v3.7.23) died during a logging upgrade with a potentially related issue (affecting the es pod):


STDOUT:

red
Using module file /usr/lib/python2.7/site-packages/ansible/modules/commands/command.py
<52.14.191.156> ESTABLISH SSH CONNECTION FOR USER: root
<52.14.191.156> SSH: EXEC ssh -o ControlMaster=auto -o ControlPersist=600s -o StrictHostKeyChecking=no -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=root -o ConnectTimeout=10 -o ControlPath=/home/opsmedic/.ansible/cp/49aa7932ec 52.14.191.156 '/bin/sh -c '"'"'/usr/bin/python && sleep 0'"'"''
<52.14.191.156> (0, '\n{"changed": true, "end": "2018-01-12 02:53:39.954820", "stdout": "red", "cmd": "oc exec \\"logging-es-data-master-szybvfio-10-5tf6r\\" -c elasticsearch -n \\"logging\\" -- curl -s --cacert /etc/elasticsearch/secret/admin-ca --cert /etc/elasticsearch/secret/admin-cert --key /etc/elasticsearch/secret/admin-key https://localhost:9200/_cat/health | cut -d\' \' -f4", "rc": 0, "start": "2018-01-12 02:53:39.382913", "stderr": "", "delta": "0:00:00.571907", "invocation": {"module_args": {"warn": true, "executable": null, "_uses_shell": true, "_raw_params": "oc exec \\"logging-es-data-master-szybvfio-10-5tf6r\\" -c elasticsearch -n \\"logging\\" -- curl -s --cacert /etc/elasticsearch/secret/admin-ca --cert /etc/elasticsearch/secret/admin-cert --key /etc/elasticsearch/secret/admin-key https://localhost:9200/_cat/health | cut -d\' \' -f4", "removes": null, "creates": null, "chdir": null, "stdin": null}}}\n', '')
FAILED - RETRYING: Waiting for ES to be ready for logging-es-data-master-szybvfio (2 retries left).Result was: {
    "attempts": 59, 
    "changed": false, 
    "cmd": "oc exec \"logging-es-data-master-szybvfio-10-5tf6r\" -c elasticsearch -n \"logging\" -- curl -s --cacert /etc/elasticsearch/secret/admin-ca --cert /etc/elasticsearch/secret/admin-cert --key /etc/elasticsearch/secret/admin-key https://localhost:9200/_cat/health | cut -d' ' -f4", 
    "delta": "0:00:00.571907", 
    "end": "2018-01-12 02:53:39.954820", 
    "failed": false, 
    "invocation": {
        "module_args": {
            "_raw_params": "oc exec \"logging-es-data-master-szybvfio-10-5tf6r\" -c elasticsearch -n \"logging\" -- curl -s --cacert /etc/elasticsearch/secret/admin-ca --cert /etc/elasticsearch/secret/admin-cert --key /etc/elasticsearch/secret/admin-key https://localhost:9200/_cat/health | cut -d' ' -f4", 
            "_uses_shell": true, 
            "chdir": null, 
            "creates": null, 
            "executable": null, 
            "removes": null, 
            "stdin": null, 
            "warn": true
        }
    }, 
    "rc": 0, 
    "retries": 61, 
    "start": "2018-01-12 02:53:39.382913"
}

STDOUT:

red
Using module file /usr/lib/python2.7/site-packages/ansible/modules/commands/command.py
<52.14.191.156> ESTABLISH SSH CONNECTION FOR USER: root
<52.14.191.156> SSH: EXEC ssh -o ControlMaster=auto -o ControlPersist=600s -o StrictHostKeyChecking=no -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=root -o ConnectTimeout=10 -o ControlPath=/home/opsmedic/.ansible/cp/49aa7932ec 52.14.191.156 '/bin/sh -c '"'"'/usr/bin/python && sleep 0'"'"''
<52.14.191.156> (0, '\n{"changed": true, "end": "2018-01-12 02:53:45.727812", "stdout": "red", "cmd": "oc exec \\"logging-es-data-master-szybvfio-10-5tf6r\\" -c elasticsearch -n \\"logging\\" -- curl -s --cacert /etc/elasticsearch/secret/admin-ca --cert /etc/elasticsearch/secret/admin-cert --key /etc/elasticsearch/secret/admin-key https://localhost:9200/_cat/health | cut -d\' \' -f4", "rc": 0, "start": "2018-01-12 02:53:45.155783", "stderr": "", "delta": "0:00:00.572029", "invocation": {"module_args": {"warn": true, "executable": null, "_uses_shell": true, "_raw_params": "oc exec \\"logging-es-data-master-szybvfio-10-5tf6r\\" -c elasticsearch -n \\"logging\\" -- curl -s --cacert /etc/elasticsearch/secret/admin-ca --cert /etc/elasticsearch/secret/admin-cert --key /etc/elasticsearch/secret/admin-key https://localhost:9200/_cat/health | cut -d\' \' -f4", "removes": null, "creates": null, "chdir": null, "stdin": null}}}\n', '')
FAILED - RETRYING: Waiting for ES to be ready for logging-es-data-master-szybvfio (1 retries left).Result was: {
    "attempts": 60, 
    "changed": false, 
    "cmd": "oc exec \"logging-es-data-master-szybvfio-10-5tf6r\" -c elasticsearch -n \"logging\" -- curl -s --cacert /etc/elasticsearch/secret/admin-ca --cert /etc/elasticsearch/secret/admin-cert --key /etc/elasticsearch/secret/admin-key https://localhost:9200/_cat/health | cut -d' ' -f4", 
    "delta": "0:00:00.572029", 
    "end": "2018-01-12 02:53:45.727812", 
    "failed": false, 
    "invocation": {
        "module_args": {
            "_raw_params": "oc exec \"logging-es-data-master-szybvfio-10-5tf6r\" -c elasticsearch -n \"logging\" -- curl -s --cacert /etc/elasticsearch/secret/admin-ca --cert /etc/elasticsearch/secret/admin-cert --key /etc/elasticsearch/secret/admin-key https://localhost:9200/_cat/health | cut -d' ' -f4", 
            "_uses_shell": true, 
            "chdir": null, 
            "creates": null, 
            "executable": null, 
            "removes": null, 
            "stdin": null, 
            "warn": true
        }
    }, 
    "rc": 0, 
    "retries": 61, 
    "start": "2018-01-12 02:53:45.155783"
}

STDOUT:

red
Using module file /usr/lib/python2.7/site-packages/ansible/modules/commands/command.py
<52.14.191.156> ESTABLISH SSH CONNECTION FOR USER: root
<52.14.191.156> SSH: EXEC ssh -o ControlMaster=auto -o ControlPersist=600s -o StrictHostKeyChecking=no -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=root -o ConnectTimeout=10 -o ControlPath=/home/opsmedic/.ansible/cp/49aa7932ec 52.14.191.156 '/bin/sh -c '"'"'/usr/bin/python && sleep 0'"'"''
<52.14.191.156> (0, '\n{"changed": true, "end": "2018-01-12 02:53:51.553986", "stdout": "red", "cmd": "oc exec \\"logging-es-data-master-szybvfio-10-5tf6r\\" -c elasticsearch -n \\"logging\\" -- curl -s --cacert /etc/elasticsearch/secret/admin-ca --cert /etc/elasticsearch/secret/admin-cert --key /etc/elasticsearch/secret/admin-key https://localhost:9200/_cat/health | cut -d\' \' -f4", "rc": 0, "start": "2018-01-12 02:53:50.934301", "stderr": "", "delta": "0:00:00.619685", "invocation": {"module_args": {"warn": true, "executable": null, "_uses_shell": true, "_raw_params": "oc exec \\"logging-es-data-master-szybvfio-10-5tf6r\\" -c elasticsearch -n \\"logging\\" -- curl -s --cacert /etc/elasticsearch/secret/admin-ca --cert /etc/elasticsearch/secret/admin-cert --key /etc/elasticsearch/secret/admin-key https://localhost:9200/_cat/health | cut -d\' \' -f4", "removes": null, "creates": null, "chdir": null, "stdin": null}}}\n', '')
failed: [52.14.191.156] (item=logging-es-data-master-szybvfio-10-5tf6r) => {
    "_pod": "logging-es-data-master-szybvfio-10-5tf6r", 
    "attempts": 60, 
    "changed": false, 
    "cmd": "oc exec \"logging-es-data-master-szybvfio-10-5tf6r\" -c elasticsearch -n \"logging\" -- curl -s --cacert /etc/elasticsearch/secret/admin-ca --cert /etc/elasticsearch/secret/admin-cert --key /etc/elasticsearch/secret/admin-key https://localhost:9200/_cat/health | cut -d' ' -f4", 
    "delta": "0:00:00.619685", 
    "end": "2018-01-12 02:53:51.553986", 
    "failed": true, 
    "invocation": {
        "module_args": {
            "_raw_params": "oc exec \"logging-es-data-master-szybvfio-10-5tf6r\" -c elasticsearch -n \"logging\" -- curl -s --cacert /etc/elasticsearch/secret/admin-ca --cert /etc/elasticsearch/secret/admin-cert --key /etc/elasticsearch/secret/admin-key https://localhost:9200/_cat/health | cut -d' ' -f4", 
            "_uses_shell": true, 
            "chdir": null, 
            "creates": null, 
            "executable": null, 
            "removes": null, 
            "stdin": null, 
            "warn": true
        }
    }, 
    "rc": 0, 
    "start": "2018-01-12 02:53:50.934301"
}

STDOUT:

red
included: /home/opsmedic/aos-cd/tmp/tmp.TkGQNfxeyn/openshift-ansible_extract/roles/openshift_logging_elasticsearch/tasks/restart_es_node.yml for 52.14.191.156

RUNNING HANDLER [openshift_logging_elasticsearch : command] ********************
Friday 12 January 2018  02:53:51 +0000 (0:05:50.560)       0:12:14.791 ******** 

RUNNING HANDLER [openshift_logging_elasticsearch : oc_obj] *********************
Friday 12 January 2018  02:53:51 +0000 (0:00:00.000)       0:12:14.792 ******** 

RUNNING HANDLER [openshift_logging_elasticsearch : command] ********************
Friday 12 January 2018  02:53:51 +0000 (0:00:00.000)       0:12:14.792 ******** 

RUNNING HANDLER [openshift_logging_elasticsearch : command] ********************
Friday 12 January 2018  02:53:51 +0000 (0:00:00.000)       0:12:14.792 ******** 
included: /home/opsmedic/aos-cd/tmp/tmp.TkGQNfxeyn/openshift-ansible_extract/roles/openshift_logging_elasticsearch/tasks/restart_es_node.yml for 52.14.191.156

RUNNING HANDLER [openshift_logging_elasticsearch : command] ********************
Friday 12 January 2018  02:53:51 +0000 (0:00:00.012)       0:12:14.804 ******** 

RUNNING HANDLER [openshift_logging_elasticsearch : oc_obj] *********************
Friday 12 January 2018  02:53:51 +0000 (0:00:00.000)       0:12:14.805 ******** 

RUNNING HANDLER [openshift_logging_elasticsearch : command] ********************
Friday 12 January 2018  02:53:51 +0000 (0:00:00.000)       0:12:14.805 ******** 

RUNNING HANDLER [openshift_logging_elasticsearch : command] ********************
Friday 12 January 2018  02:53:51 +0000 (0:00:00.000)       0:12:14.805 ******** 

RUNNING HANDLER [openshift_logging_elasticsearch : command] ********************
Friday 12 January 2018  02:53:51 +0000 (0:00:00.000)       0:12:14.806 ******** 

RUNNING HANDLER [openshift_logging_elasticsearch : command] ********************
Friday 12 January 2018  02:53:51 +0000 (0:00:00.000)       0:12:14.806 ******** 

RUNNING HANDLER [openshift_logging_elasticsearch : oc_service] *****************
Friday 12 January 2018  02:53:51 +0000 (0:00:00.000)       0:12:14.806 ******** 

RUNNING HANDLER [openshift_logging_elasticsearch : set_fact] *******************
Friday 12 January 2018  02:53:51 +0000 (0:00:00.000)       0:12:14.807 ******** 

RUNNING HANDLER [openshift_logging_elasticsearch : Restarting logging-{{ _cluster_component }} cluster] ***
Friday 12 January 2018  02:53:51 +0000 (0:00:00.000)       0:12:14.807 ******** 

RUNNING HANDLER [openshift_logging_elasticsearch : set_fact] *******************
Friday 12 January 2018  02:53:51 +0000 (0:00:00.000)       0:12:14.807 ******** 

RUNNING HANDLER [openshift_logging_elasticsearch : Restarting logging-{{ _cluster_component }} cluster] ***
Friday 12 January 2018  02:53:51 +0000 (0:00:00.000)       0:12:14.807 ******** 

RUNNING HANDLER [openshift_logging_elasticsearch : set_fact] *******************
Friday 12 January 2018  02:53:51 +0000 (0:00:00.000)       0:12:14.808 ******** 
META: ran handlers

PLAY RECAP *********************************************************************
13.58.250.236              : ok=43   changed=6    unreachable=0    failed=0   
18.216.58.38               : ok=43   changed=6    unreachable=0    failed=0   
18.221.227.84              : ok=43   changed=6    unreachable=0    failed=0   
52.14.176.225              : ok=43   changed=6    unreachable=0    failed=0   
52.14.191.156              : ok=283  changed=60   unreachable=0    failed=1   
52.14.73.0                 : ok=43   changed=6    unreachable=0    failed=0   
52.14.75.147               : ok=43   changed=6    unreachable=0    failed=0   
52.14.8.110                : ok=44   changed=6    unreachable=0    failed=0   
52.15.151.129              : ok=43   changed=6    unreachable=0    failed=0   
52.15.177.230              : ok=44   changed=6    unreachable=0    failed=0   
localhost                  : ok=11   changed=0    unreachable=0    failed=0

Comment 7 Anping Li 2018-01-14 09:06:38 UTC

I guess logging-es-data-master-szybvfio-8-mbnkv is the ES pod name before upgrade. I hit similar issue in v3.9 https://bugzilla.redhat.com/show_bug.cgi?id=1533783

Comment 10 Peter Portante 2018-03-02 02:23:18 UTC

A logging upgrade should not proceed if an Elasticsearch cluster is in an unhealthy state.  It looks as if o-a PR 6734 takes care of this.  Do we have a QE test that can cover this condition?

Comment 11 Anping Li 2018-03-02 02:42:54 UTC

Peter,  we haven't cases to cover this point.  But I hit red status issue during 3.7-3.9 upgrade yesterday.  The ES rolling restart are skipped with a warning message. the openshift-ansible verison is v3.9.1-1. I am not sure if the PR have been merged to v3.7.

Comment 12 ewolinet 2018-03-02 16:09:55 UTC

This should be merged into 3.7 at this point.

Comment 13 Anping Li 2018-03-28 07:06:47 UTC

@ewolinet,  The cluster states checking is in restart_cluster.yml which is called by ansible handler. I think it is too later, it is better to check status at the beginning.

For example:
1) When I remove the first ES dc, the ES is in red status. Logging upgrade will failed in PVC checking steps.
TASK [openshift_logging_elasticsearch : Check to see if PVC already exists] ****
task path: /usr/share/ansible/openshift-ansible/roles/openshift_logging_elasticsearch/tasks/main.yaml:342
fatal: [host-8-249-31.host.centralci.eng.rdu2.redhat.com]: FAILED! => {"failed": true, "msg": "the field 'args' has an invalid value, which appears to include a variable that is undefined. The error was: {{ outer_item.0.volumes['elasticsearch-storage'].persistentVolumeClaim.claimName if outer_item.0.volumes['elasticsearch-storage'].persistentVolumeClaim is defined else openshift_logging_es_pvc_prefix ~ '-' ~ outer_item.2 if outer_item.1 is none else outer_item.1 }}: 'None' has no attribute 'volumes'\n\nThe error appears to have been in '/usr/share/ansible/openshift-ansible/roles/openshift_logging_elasticsearch/tasks/main.yaml': line 342, column 3, but may\nbe elsewhere in the file depending on the exact syntax problem.\n\nThe offending line appears to be:\n\n\n- name: Check to see if PVC already exists\n  ^ here\n"}

Comment 14 ewolinet 2018-03-29 20:27:21 UTC

@anli,

Those are two different issues. The act of not doing a rollout if the cluster is red is to prevent loss of data by doing a rolling cluster restart and because we would need to do a manual recovery of data first before we try to roll out new cluster changes.

Comment 15 Anping Li 2018-03-30 02:43:55 UTC

ewolinet, got it.  There is a risk. if the playbook aborts in restart_cluster.yml, Some of Elasticsearch pod may be upgraded. The other aren't.  The ES may be in inconsistency.

Comment 16 Anping Li 2018-03-30 02:49:24 UTC

Test with openshift-ansible:v3.7.40. 
The following message will be printed when the ES status is red.
"Cluster logging-elasticsearch was in a red state and will not be automatically restarted. Please see documentation regarding doing a full cluster restart.

Note that: if the upgrade abort in this status. some ES may be upgraded while some aren't. and the fluent/kibana/curator aren't upgraded. Redeploy logging are required to finish upgrade/redeploy.

Comment 17 ewolinet 2018-04-02 16:11:17 UTC

That shouldn't be the case -- the restarting of the nodes is done in a handler which is executed at the end of the playbook run. So we would have upgraded all of our other logging components and we shouldn't see some ES dcs updated and some not, we would update the DCs but would not perform out oc rollout latest commands against them.