Bug 1468847

Summary:

Repeated exceptions for deleted namespace in logging-mux pod logs

Product:

OpenShift Container Platform

Reporter:

Mike Fiedler <mifiedle>

Component:

Logging

Assignee:

Rich Megginson <rmeggins>

Status:

CLOSED WORKSFORME

QA Contact:

Xia Zhao <xiazhao>

Severity:

medium

Docs Contact:

Priority:

unspecified

Version:

3.6.0

CC:

aos-bugs, cstark, mifiedle, nhosoi, pportant, rmeggins

Target Milestone:

---

Keywords:

Reopened

Target Release:

---

Hardware:

x86_64

OS:

Linux

Whiteboard:

Fixed In Version:

Doc Type:

If docs needed, set a value

Doc Text:

Story Points:

---

Clone Of:

Clones:

1550137 (view as bug list)

Environment:

Last Closed:

2018-02-28 15:36:52 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:

Bug Blocks:

1550137

Attachments:

Description	Flags
logging-mux pod log showing the issue	none

Description Mike Fiedler 2017-07-08 21:12:05 UTC

Created attachment 1295508 [details]
logging-mux pod log showing the issue

Description of problem:

In the scalability cluster, the logging-mux pod log contains repeated exceptions for a namespace/project that has been deleted for several days.   I've tried to chase down where it might be finding information on this project, but unsuccessful so far.

The error:


2017-07-08 16:05:18 -0400 [warn]: emit transaction failed: error_class=KubeException error="HTTP status code 404, namespaces \"logtest0\" not found" tag="kubernetes.journal.container"
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/kubeclient-1.1.4/lib/kubeclient/common.rb:66:in `rescue in handle_exception'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/kubeclient-1.1.4/lib/kubeclient/common.rb:58:in `handle_exception'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/kubeclient-1.1.4/lib/kubeclient/common.rb:202:in `get_entity'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/kubeclient-1.1.4/lib/kubeclient/common.rb:103:in `block (2 levels) in define_entity_methods'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluent-plugin-kubernetes_metadata_filter-0.26.2/lib/fluent/plugin/filter_kubernetes_metadata.rb:293:in `block (3 levels) in filter_stream_from_journal'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/lru_redux-1.1.0/lib/lru_redux/ttl/cache.rb:52:in `getset'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/lru_redux-1.1.0/lib/lru_redux/util/safe_sync.rb:26:in `block in getset'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/ruby/monitor.rb:211:in `mon_synchronize'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/lru_redux-1.1.0/lib/lru_redux/util/safe_sync.rb:25:in `getset'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluent-plugin-kubernetes_metadata_filter-0.26.2/lib/fluent/plugin/filter_kubernetes_metadata.rb:292:in `block (2 levels) in filter_stream_from_journal'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluent-plugin-kubernetes_metadata_filter-0.26.2/lib/fluent/plugin/filter_kubernetes_metadata.rb:266:in `match'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluent-plugin-kubernetes_metadata_filter-0.26.2/lib/fluent/plugin/filter_kubernetes_metadata.rb:266:in `block in filter_stream_from_journal'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluentd-0.12.31/lib/fluent/event.rb:56:in `call'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluentd-0.12.31/lib/fluent/event.rb:56:in `each'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluent-plugin-kubernetes_metadata_filter-0.26.2/lib/fluent/plugin/filter_kubernetes_metadata.rb:261:in `filter_stream_from_journal'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluentd-0.12.31/lib/fluent/event_router.rb:152:in `block in emit'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluentd-0.12.31/lib/fluent/event_router.rb:151:in `each'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluentd-0.12.31/lib/fluent/event_router.rb:151:in `emit'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluentd-0.12.31/lib/fluent/event_router.rb:90:in `emit_stream'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluentd-0.12.31/lib/fluent/event_router.rb:81:in `emit'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluent-plugin-rewrite-tag-filter-1.5.5/lib/fluent/plugin/out_rewrite_tag_filter.rb:75:in `block in emit'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluentd-0.12.31/lib/fluent/event.rb:130:in `call'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluentd-0.12.31/lib/fluent/event.rb:130:in `block in each'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluentd-0.12.31/lib/fluent/event.rb:129:in `each'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluentd-0.12.31/lib/fluent/event.rb:129:in `each'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluent-plugin-rewrite-tag-filter-1.5.5/lib/fluent/plugin/out_rewrite_tag_filter.rb:72:in `emit'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluentd-0.12.31/lib/fluent/event_router.rb:154:in `emit'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluentd-0.12.31/lib/fluent/event_router.rb:90:in `emit_stream'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluentd-0.12.31/lib/fluent/plugin/out_relabel.rb:24:in `emit'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluentd-0.12.31/lib/fluent/event_router.rb:90:in `emit_stream'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluent-plugin-secure-forward-0.4.3/lib/fluent/plugin/in_secure_forward.rb:293:in `on_message'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluent-plugin-secure-forward-0.4.3/lib/fluent/plugin/input_session.rb:124:in `on_read'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluent-plugin-secure-forward-0.4.3/lib/fluent/plugin/input_session.rb:185:in `feed_each'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluent-plugin-secure-forward-0.4.3/lib/fluent/plugin/input_session.rb:185:in `block in start'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluent-plugin-secure-forward-0.4.3/lib/fluent/plugin/input_session.rb:178:in `loop'
  2017-07-08 16:05:18 -0400 [warn]: /usr/share/gems/gems/fluent-plugin-secure-forward-0.4.3/lib/fluent/plugin/input_session.rb:178:in `start'
2017-07-08 16:05:19 -0400 [warn]: emit transaction failed: error_class=KubeException error="HTTP status code 404, namespaces \"logtest0\" not found" tag="journal"
  2017-07-08 16:05:19 -0400 [warn]: suppressed same stacktrace
2017-07-08 16:05:19 -0400 [warn]: emit transaction failed: error_class=KubeException error="HTTP status code 404, namespaces \"logtest0\" not found" tag="journal"
  2017-07-08 16:05:19 -0400 [warn]: suppressed same stacktrace
2017-07-08 16:05:19 -0400 [warn]: unexpected error in in_secure_forward from 10.131.0.1:42364 error_class=KubeException error=#<KubeException: HTTP status code 404, namespaces "logtest0" not found>
2017-07-08 16:05:38 -0400 [warn]: emit transaction failed: error_class=KubeException error="HTTP status code 404, namespaces \"logtest0\" not found" tag="kubernetes.journal.container"

Other deleted project areas previously indexed are not appearing - just this particular one.


Version-Release number of selected component (if applicable): Logging 3.6.126.1


How reproducible: Always so far when deploying logging-mux in this cluster

Comment 1 Rich Megginson 2017-07-10 20:34:40 UTC

Is it possible you have some node configured with `journal_read_from_head true`?  If so, then it would appear it is picking up some old log record from the journal on that system.

Comment 2 Rich Megginson 2017-07-11 19:55:35 UTC

What would be the preferred action when fluentd or mux attempts to look up a namespace that does not exist?

Comment 3 Mike Fiedler 2017-07-11 20:24:27 UTC

These exceptions eventually went away.  It appeared at the time I opened the bz that we were never going to give up on that namespace - even through restarts of all of the logging infra.   I do not now believe this is a pressing issue - I was more concerned that the deleted namespace would be sticky.

Comment 4 Rich Megginson 2017-07-11 20:28:51 UTC

(In reply to Mike Fiedler from comment #3)
> These exceptions eventually went away.  It appeared at the time I opened the
> bz that we were never going to give up on that namespace - even through
> restarts of all of the logging infra.   I do not now believe this is a
> pressing issue - I was more concerned that the deleted namespace would be
> sticky.

Ok - if this happens again, I'd like to examine the cluster and figure out where the deleted namespace is coming from.

What would you like to do with this bz?  Can we close it?

Comment 5 Mike Fiedler 2017-07-12 00:42:12 UTC

Per comment 3 and comment 4, closing this as works for me.    We can re-visit it if encountered on the latest fluentd container image.

Comment 7 Mike Fiedler 2018-02-28 15:36:52 UTC

This was fixed in 3.6/3.7 by sending index entries for deleted namespaces to an orphan index.   Dev will have to say if that was backported further.   I recommend opening a new bz for the customer issue so it does not get confused with an issue found in 3.6.   You can clone this bz if you'd like.