Bug 1928772
| Summary: | Sometimes the elasticsearch-delete-xxx job failed: After OCP 4.6.16 patch. | ||
|---|---|---|---|
| Product: | OpenShift Container Platform | Reporter: | David Hernández Fernández <dahernan> |
| Component: | Logging | Assignee: | ewolinet |
| Status: | CLOSED ERRATA | QA Contact: | Qiaoling Tang <qitang> |
| Severity: | high | Docs Contact: | |
| Priority: | high | ||
| Version: | 4.6 | CC: | achakrat, akhaire, alchan, andcosta, anisal, anli, aos-bugs, apaladug, ausov, aygarg, ChetRHosey, cruhm, dageoffr, dahernan, dapark, dkulkarn, dseals, ewolinet, fgiloux, gkarager, jcantril, juherrer, kiyyappa, knakai, ksathe, luaparicio, lvlcek, mmohan, mrdest, mrobson, naoto30, nnosenzo, ocasalsa, openshift-bugs-escalate, periklis, prdeshpa, qitang, rkant, rnoma, rsandu, sauchter, shishika, sreber, ssadhale, ssonigra, tmicheli, travi, vhernand, vjaypurk, xingli, ykarajag |
| Target Milestone: | --- | Keywords: | ServiceDeliveryImpact |
| Target Release: | 4.6.z | ||
| Hardware: | All | ||
| OS: | Unspecified | ||
| Whiteboard: | logging-exploration | ||
| Fixed In Version: | Doc Type: | Bug Fix | |
| Doc Text: |
* Previously, while under load, Elasticsearch responded to some requests with an HTTP 500 error, even though there was nothing wrong with the cluster. Retrying the request was successful. This release fixes the issue by updating the cron jobs to be more resilient when encountering temporary HTTP 500 errors. Now, they will retry a request multiple times first before failing.
(link:https://bugzilla.redhat.com/show_bug.cgi?id=1928772[*BZ#1928772*])
|
Story Points: | --- |
| Clone Of: | 1916910 | Environment: | |
| Last Closed: | 2021-03-30 16:54:58 UTC | Type: | --- |
| 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: | 1890838, 1916910 | ||
| Bug Blocks: | 1919075 | ||
|
Description
David Hernández Fernández
2021-02-15 14:30:54 UTC
Hello, I can see exactly the same issue that in BZ#1916910 that it was fixed in OCP 4.6.16. ~~~ # oc get pods NAME READY STATUS RESTARTS AGE cluster-logging-operator-7c87c4dfbd-vppsv 1/1 Running 0 18h curator-1613619000-k8mbd 0/1 Completed 0 12h elasticsearch-cdm-qarn9lmr-1-5fb9cc7bf5-dhlth 2/2 Running 0 18h elasticsearch-cdm-qarn9lmr-2-645bf4cd96-gxbl4 2/2 Running 0 18h elasticsearch-cdm-qarn9lmr-3-8d4c95d8f-9cg6g 2/2 Running 0 18h elasticsearch-im-app-1613664000-xdr8j 0/1 Completed 0 8m33s elasticsearch-im-audit-1613664000-d672l 0/1 Completed 0 8m33s elasticsearch-im-infra-1613655900-kdcdc 0/1 Error 0 143m elasticsearch-im-infra-1613664000-j2zsh 0/1 Completed 0 8m33s ... # oc logs pod/elasticsearch-im-infra-1613655900-kdcdc deleting indices: infra-000719 { "error" : { "root_cause" : [ { "type" : "security_exception", "reason" : "Unexpected exception indices:admin/delete" } ], "type" : "security_exception", "reason" : "Unexpected exception indices:admin/delete" }, "status" : 500 } Current write index for infra-write: infra-000740 Checking results from _rollover call Next write index for infra-write: infra-000740 Checking if infra-000740 exists Checking if infra-000740 is the write index for infra-write Done! ~~~ Then, as Víctor has asked before, should we create a separate bugzilla for this that it's the same that it was tried to fix in BZ#1916910 and leaving this Bug only for the error related to the error? "cat: /tmp/response.txt: No such file or directory" Best regards, Oscar > # oc logs pod/elasticsearch-im-infra-1613655900-kdcdc
>
> deleting indices: infra-000719
> {
> "error" : {
> "root_cause" : [
> {
> "type" : "security_exception",
> "reason" : "Unexpected exception indices:admin/delete"
> }
> ],
> "type" : "security_exception",
> "reason" : "Unexpected exception indices:admin/delete"
> },
> "status" : 500
> }
This looks like an security issue with having permissions to delete -- do you seem the same errors in the ES pod logs as Victor posted above?
If so could you provide a must-gather for the cluster? I had requested one for this specific issue and have not yet received one.
*** Bug 1937216 has been marked as a duplicate of this bug. *** Testing with elasticsearch-operator.4.6.0-202103202154.p0, I set the index management cronjobs to run in every 3 minutes and the ES cluster is running for about 29 hours, no job fails. $ oc get pod NAME READY STATUS RESTARTS AGE cluster-logging-operator-6f66778f94-7zpmh 1/1 Running 0 29h elasticsearch-cdm-kbvuvj7o-1-5989bcf7c4-vkxrc 2/2 Running 0 29h elasticsearch-cdm-kbvuvj7o-2-57468594c7-5n8kf 2/2 Running 0 29h elasticsearch-cdm-kbvuvj7o-3-5df4bc888d-5dx8h 2/2 Running 0 29h elasticsearch-im-app-1616659740-dx989 0/1 Completed 0 79s elasticsearch-im-audit-1616659740-p26qw 0/1 Completed 0 79s elasticsearch-im-infra-1616659740-swdt7 0/1 Completed 0 79s fluentd-bsjzw 1/1 Running 0 29h fluentd-fsl9g 1/1 Running 0 29h fluentd-pjqzd 1/1 Running 0 29h fluentd-rdfkt 1/1 Running 0 29h fluentd-tv9hh 1/1 Running 0 29h fluentd-v6w9f 1/1 Running 0 29h kibana-8685fbf674-c9fct 2/2 Running 0 29h Move this bz to verified. I think 29 hours is not enough, could you verify it a bit further, please? (i.e 1 week) This bug has been "verified" in the past as well in other situations but happened after a few days. (In reply to David Hernández Fernández from comment #45) > I think 29 hours is not enough, could you verify it a bit further, please? > (i.e 1 week) This bug has been "verified" in the past as well in other > situations but happened after a few days. Hi David, I tested with an earlier version(elasticsearch-operator.4.6.0-202103010126.p0) which doesn't have the fix, the issue reproduced after ES cluster running for 7 hours. Compared to the result in comment 44, I think the condition has significant improvement, so I verified this bz. $ oc get pod NAME READY STATUS RESTARTS AGE cluster-logging-operator-79c8f9b6d5-ldgg6 1/1 Running 0 8h elasticsearch-cdm-s6xfukoa-1-6989d86b54-gpjkm 2/2 Running 0 7h58m elasticsearch-cdm-s6xfukoa-2-85f7f5bc7c-7tj6x 2/2 Running 0 7h57m elasticsearch-cdm-s6xfukoa-3-5d7ccfbb96-ssthc 2/2 Running 0 7h56m elasticsearch-im-app-1617007320-8q74b 0/1 Completed 0 96s elasticsearch-im-audit-1617007320-r787v 0/1 Completed 0 96s elasticsearch-im-infra-1617003900-5lzqd 0/1 Error 0 58m elasticsearch-im-infra-1617007320-wm9r6 0/1 Completed 0 96s Anyway, I'll follow your advice to keep my another cluster running for 1 week to see if the issue could be reproduced with the fix. (In reply to Qiaoling Tang from comment #47) > (In reply to David Hernández Fernández from comment #45) > > I think 29 hours is not enough, could you verify it a bit further, please? > > (i.e 1 week) This bug has been "verified" in the past as well in other > > situations but happened after a few days. > > Hi David, > > I tested with an earlier > version(elasticsearch-operator.4.6.0-202103010126.p0) which doesn't have the > fix, the issue reproduced after ES cluster running for 7 hours. Compared to > the result in comment 44, I think the condition has significant improvement, > so I verified this bz. > > $ oc get pod > NAME READY STATUS RESTARTS > AGE > cluster-logging-operator-79c8f9b6d5-ldgg6 1/1 Running 0 > 8h > elasticsearch-cdm-s6xfukoa-1-6989d86b54-gpjkm 2/2 Running 0 > 7h58m > elasticsearch-cdm-s6xfukoa-2-85f7f5bc7c-7tj6x 2/2 Running 0 > 7h57m > elasticsearch-cdm-s6xfukoa-3-5d7ccfbb96-ssthc 2/2 Running 0 > 7h56m > elasticsearch-im-app-1617007320-8q74b 0/1 Completed 0 > 96s > elasticsearch-im-audit-1617007320-r787v 0/1 Completed 0 > 96s > elasticsearch-im-infra-1617003900-5lzqd 0/1 Error 0 > 58m > elasticsearch-im-infra-1617007320-wm9r6 0/1 Completed 0 > 96s > > Anyway, I'll follow your advice to keep my another cluster running for 1 > week to see if the issue could be reproduced with the fix. To expand on this, previously we didn't have a method to consistently reproduce this issue. This was something I could consistently have happen multiple times an hour and I had conveyed the method to recreate it locally to QE. Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory (OpenShift Container Platform 4.6.23 extras update), and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHBA-2021:0954 Still seeing it 4.7.21, but with a different error in the logs:
# oc logs elasticsearch-im-audit-1631027700-8gqhd
========================
Index management delete process starting for audit
No indices to delete
========================
Index management delete process starting for {"error":{"root_cause":[{"type":"security_exception","reason":"_opendistro_security_dls_query
Received an empty response from elasticsearch -- server may not be ready
========================
Index management rollover process starting for audit
Current write index for audit-write: audit-000011
Checking results from _rollover call
Next write index for audit-write: audit-000011
Checking if audit-000011 exists
Checking if audit-000011 is the write index for audit-write
Done!
|