Bug 1756166

The purpose of this Bugzilla report is to provide a referent for Bug 1752521, which tracks the 4.1 backport of https://github.com/openshift/router/pull/7, which was merged in 4.2 without a Bugzilla report.

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


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

Description of problem:

Project with 2 routes points to a single service with 2 named ports.

One is for a health check and the other is for application traffic.

When start / deploying and the health check is up, but the application is still starting, we see traffic on the application route being sent to the health check containers resulting in 404s.

This pod has 2 containers, the application and a sidecar for add-on services which include the health check.

Requests to project-lb.public.com target the app port which points to the application container. When the application container is still starting, they are seeing a number of 404 errors for traffic.

From what we can see, when the application comes up, it stops sending traffic incorrectly to the health check container.

Turning on debug logging for the health check container, we can see traffic for project-lb.public.com is incorrectly coming into the health check container and returning 404s.

Health Check Route:

apiVersion: v1
items:
- apiVersion: route.openshift.io/v1
  kind: Route
  metadata:
    creationTimestamp: 2019-03-29T19:31:23Z
    name: healthcheck
    namespace: project
    resourceVersion: "65987865"
    selfLink: /apis/route.openshift.io/v1/namespaces/project/routes/healthcheck
    uid: 3c9c3612-5259-11e9-a732-005056b97b10
  spec:
    host: healthcheck.paas.com
    port:
      targetPort: hm
    to:
      kind: Service
      name: svc-act
      weight: 100
    wildcardPolicy: None
  status:
    ingress:
    - conditions:
      - lastTransitionTime: 2019-03-29T19:31:23Z
        status: "True"
        type: Admitted
      routerName: router
      wildcardPolicy: None

Application Route:


- apiVersion: route.openshift.io/v1
  kind: Route
  metadata:
    creationTimestamp: 2019-03-29T19:31:05Z
    name: application
    namespace: project
    resourceVersion: "65987845"
    selfLink: /apis/route.openshift.io/v1/namespaces/project/routes/application
    uid: 31a7d081-5259-11e9-a732-005056b97b10
  spec:
    host: project-lb.public.com
    port:
      targetPort: app
    tls:
      termination: edge
    to:
      kind: Service
      name: svc-act
      weight: 100
    wildcardPolicy: None
  status:
    ingress:
    - conditions:
      - lastTransitionTime: 2019-03-29T19:31:05Z
        status: "True"
        type: Admitted
      routerName: router
      wildcardPolicy: None


Service:

apiVersion: v1
items:
- apiVersion: v1
  kind: Service
  metadata:
    annotations:
      kubectl.kubernetes.io/last-applied-configuration: |
        {"apiVersion":"v1","kind":"Service","metadata":{"annotations":{},"name":"svc-act","namespace":"project"},"spec":{"ports":[{"name":"app","port":8080,"targetPort":8080},{"name":"hm","port":8081,"targetPort":9011}],"selector":{"name":"project-b"}}}
    creationTimestamp: 2019-03-29T19:31:09Z
    name: svc-act
    namespace: project
    resourceVersion: "80400351"
    selfLink: /api/v1/namespaces/project/services/svc-act
    uid: 3483c483-5259-11e9-a366-005056b97ad5
  spec:
    clusterIP: 172.29.82.203
    ports:
    - name: app
      port: 8080
      protocol: TCP
      targetPort: 8080
    - name: hm
      port: 8081
      protocol: TCP
      targetPort: 9011
    selector:
      name: project-b
    sessionAffinity: None
    type: ClusterIP
  status:
    loadBalancer: {}


Health Check Log showing traffic for project-lb.public.com coming into port 9011 which is the health check port 'hm'

2019-07-16 14:50:27.450 DEBUG 8 --- [http-nio-9011-Acceptor-0] o.apache.tomcat.util.threads.LimitLatch  : Counting up[http-nio-9011-Acceptor-0] latch=1
2019-07-16 14:50:27.450 DEBUG 8 --- [http-nio-9011-exec-5] o.a.tomcat.util.net.SocketWrapperBase    : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@4054f4a1:org.apache.tomcat.util.net.NioChannel@699d524f:java.nio.channels.SocketChannel[connected local=/10.1.1.1:9011 remote=/10.59.28.1:37190]], Read from buffer: [0]
2019-07-16 14:50:27.451 DEBUG 8 --- [http-nio-9011-exec-5] o.a.coyote.http11.Http11InputBuffer      : Received [GET /url/info HTTP/1.1
User-Agent: curl/7.29.0
Accept: */*
X-Forwarded-For: 10.1.1.1
Host: project-lb.public.com
X-Forwarded-Host: project-lb.public.com
X-Forwarded-Port: 443
X-Forwarded-Proto: https
Forwarded: for=10.1.1.1;host=fproject-lb.public.com;proto=https

]
2019-07-16 14:50:27.451 DEBUG 8 --- [http-nio-9011-exec-5] o.a.c.authenticator.AuthenticatorBase    : Security checking request GET /url/info
2019-07-16 14:50:27.451 DEBUG 8 --- [http-nio-9011-exec-5] org.apache.catalina.realm.RealmBase      :   No applicable constraints defined
2019-07-16 14:50:27.451 DEBUG 8 --- [http-nio-9011-exec-5] o.a.c.authenticator.AuthenticatorBase    :  Not subject to any constraint
2019-07-16 14:50:27.451 DEBUG 8 --- [http-nio-9011-exec-5] o.s.b.w.f.OrderedRequestContextFilter    : Bound request context to thread: org.apache.catalina.connector.RequestFacade@12f8d3c1
2019-07-16 14:50:27.451 DEBUG 8 --- [http-nio-9011-exec-5] o.s.web.servlet.DispatcherServlet        : DispatcherServlet with name 'dispatcherServlet' processing GET request for [/url/info]
2019-07-16 14:50:27.451 DEBUG 8 --- [http-nio-9011-exec-5] s.w.s.m.m.a.RequestMappingHandlerMapping : Looking up handler method for path /url/info
2019-07-16 14:50:27.451 DEBUG 8 --- [http-nio-9011-exec-5] s.w.s.m.m.a.RequestMappingHandlerMapping : Did not find handler method for [/url/info]
2019-07-16 14:50:27.451 DEBUG 8 --- [http-nio-9011-exec-5] o.s.w.s.handler.SimpleUrlHandlerMapping  : Matching patterns for request [/url/info] are [/**]
2019-07-16 14:50:27.452 DEBUG 8 --- [http-nio-9011-exec-5] o.s.w.s.handler.SimpleUrlHandlerMapping  : URI Template variables for request [/url/info] are {}
2019-07-16 14:50:27.452 DEBUG 8 --- [http-nio-9011-exec-5] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapping [/url/info] to HandlerExecutionChain with handler [ResourceHttpRequestHandler [locations=[ServletContext resource [/], class path resource [META-INF/resources/], class path resource [resources/], class path resource [static/], class path resource [public/]], resolvers=[org.springframework.web.servlet.resource.PathResourceResolver@4b5a5ed1]]] and 1 interceptor
2019-07-16 14:50:27.452 DEBUG 8 --- [http-nio-9011-exec-5] o.s.web.servlet.DispatcherServlet        : Last-Modified value for [/url/info] is: -1
2019-07-16 14:50:27.452 DEBUG 8 --- [http-nio-9011-exec-5] o.s.web.servlet.DispatcherServlet        : Null ModelAndView returned to DispatcherServlet with name 'dispatcherServlet': assuming HandlerAdapter completed request handling
2019-07-16 14:50:27.452 DEBUG 8 --- [http-nio-9011-exec-5] o.s.web.servlet.DispatcherServlet        : Successfully completed request
2019-07-16 14:50:27.452 DEBUG 8 --- [http-nio-9011-exec-5] o.s.b.w.f.OrderedRequestContextFilter    : Cleared thread-bound request context: org.apache.catalina.connector.RequestFacade@12f8d3c1
2019-07-16 14:50:27.452 DEBUG 8 --- [http-nio-9011-exec-5] o.a.c.c.C.[Tomcat].[localhost]           : Processing ErrorPage[errorCode=0, location=/error]
2019-07-16 14:50:27.452 DEBUG 8 --- [http-nio-9011-exec-5] o.s.web.servlet.DispatcherServlet        : DispatcherServlet with name 'dispatcherServlet' processing GET request for [/error]
2019-07-16 14:50:27.453 DEBUG 8 --- [http-nio-9011-exec-5] s.w.s.m.m.a.RequestMappingHandlerMapping : Looking up handler method for path /error
2019-07-16 14:50:27.453 DEBUG 8 --- [http-nio-9011-exec-5] s.w.s.m.m.a.RequestMappingHandlerMapping : Returning handler method [public org.springframework.http.ResponseEntity<java.util.Map<java.lang.String, java.lang.Object>> org.springframework.boot.autoconfigure.web.BasicErrorController.error(javax.servlet.http.HttpServletRequest)]
2019-07-16 14:50:27.453 DEBUG 8 --- [http-nio-9011-exec-5] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'basicErrorController'
2019-07-16 14:50:27.453 DEBUG 8 --- [http-nio-9011-exec-5] o.s.web.servlet.DispatcherServlet        : Last-Modified value for [/error] is: -1
2019-07-16 14:50:27.454 DEBUG 8 --- [http-nio-9011-exec-5] o.s.w.s.m.m.a.HttpEntityMethodProcessor  : Written [{timestamp=Tue Jul 16 14:50:27 EDT 2019, status=404, error=Not Found, message=No message available, path=/url/info}] as ""application/json"" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@37e547da]
2019-07-16 14:50:27.454 DEBUG 8 --- [http-nio-9011-exec-5] o.s.web.servlet.DispatcherServlet        : Null ModelAndView returned to DispatcherServlet with name 'dispatcherServlet': assuming HandlerAdapter completed request handling
2019-07-16 14:50:27.454 DEBUG 8 --- [http-nio-9011-exec-5] o.s.web.servlet.DispatcherServlet        : Successfully completed request
2019-07-16 14:50:27.454 DEBUG 8 --- [http-nio-9011-exec-5] o.a.c.c.C.[.[.[/].[dispatcherServlet]    :  Disabling the response for further output
...
...


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

How reproducible:
Always for this application

Steps to Reproduce:
1. Customer environment
2.
3.

Actual results:
Traffic to wrong container


Expected results:
Traffic should not route to the health check container.

Additional info: