Bug 1780794 - Router emits unhelpful "another route has claimed this host" log messages
Summary: Router emits unhelpful "another route has claimed this host" log messages
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: OpenShift Container Platform
Classification: Red Hat
Component: Routing
Version: 4.3.0
Hardware: Unspecified
OS: Unspecified
medium
low
Target Milestone: ---
: 4.4.0
Assignee: Dan Mace
QA Contact: Hongan Li
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2019-12-06 23:57 UTC by Miciah Dashiel Butler Masters
Modified: 2020-05-04 11:19 UTC (History)
12 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of: 1780398
Environment:
Last Closed: 2020-05-04 11:19:04 UTC
Target Upstream Version:


Attachments (Terms of Use)


Links
System ID Priority Status Summary Last Updated
Github openshift router pull 69 'None' closed Bug 1780794: unique_host: HandleRoute: No error if host claimed 2020-11-06 16:19:03 UTC
Red Hat Product Errata RHBA-2020:0581 None None None 2020-05-04 11:19:37 UTC

Description Miciah Dashiel Butler Masters 2019-12-06 23:57:04 UTC
In investigating bug 1780398, I noticed that the router logs had thousands of log messages that were identical but for the timestamp:

    E1205 20:10:23.002883       1 router_controller.go:244] another route has claimed this host

This log message is unhelpful because it does not identify the involved routes or the host.  Moreover, it is redundant because the router emits another log message, at a higher log level, that does identify the routes and host, and the same information should be reflected in the route's status as well.  Thus the router should not emit the above log message.

+++ This bug was initially created as a clone of Bug #1780398 +++

Description of problem:

Upgrading a cluster with 2K projects from 4.2.9 to 4.3.0-0.nightly-2019-12-05-073829 failed with monitoring hung for an hour.  

[...]

--- Additional comment from Miciah Dashiel Butler Masters on 2019-12-06 18:58:26 UTC ---

The route in question was created at time 2019-12-05T20:09:20Z.  From 2019-12-05T20:09:41Z to 2019-12-05T20:12:15Z, the API was returning "forbidden: not yet ready to handle request" errors (not only to the router: I see the same error in logs for the auth operator, samples operator, CVO, and kube-controller-manager).  The router may have admitted the route, but the router failed to update the route's status due to the API outage.  The router is designed to be able to function with limited privileges.  It is not clear to me whether the router should retry on forbidden errors, or whether the API is incorrect in returning a forbidden error for a request that should be retried.

Comment 1 Miciah Dashiel Butler Masters 2019-12-07 00:03:40 UTC
In each router pod's logs, I see 9995 instances of this message logged in a period of about 11 seconds.  Just to make sure I'm not missing a more serious issue, can you confirm that the test in question created about 9995 routes with conflicting host names?

Comment 2 Mike Fiedler 2019-12-09 12:01:40 UTC
The test does create a large number of artificial routes from the same template.  I will open an issue to make those routes more realistic.

Comment 4 Hongan Li 2019-12-23 08:18:15 UTC
verified with 4.4.0-0.nightly-2019-12-20-210709 and issue has been fixed.

create two routes with same hostname, then 
oc -n openshift-ingress logs router-default-568c75cc44-8jgqf | grep "claimed"


repeat the same steps with old build then
$ oc -n openshift-ingress logs router-default-678757dd74-5nzc5 | grep "claimed"
E1223 08:10:14.876097       1 router_controller.go:244] another route has claimed this host

Comment 6 errata-xmlrpc 2020-05-04 11:19:04 UTC
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, 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-2020:0581


Note You need to log in before you can comment on or make changes to this bug.