Bug 1462397 - EnsureLoadBalancer is spammy in large clusters
Summary: EnsureLoadBalancer is spammy in large clusters
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: OpenShift Container Platform
Classification: Red Hat
Component: Networking
Version: 3.5.1
Hardware: Unspecified
OS: Unspecified
unspecified
medium
Target Milestone: ---
: 3.7.0
Assignee: Ivan Chavero
QA Contact: Meng Bo
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-06-17 04:05 UTC by Eric Paris
Modified: 2017-11-28 21:58 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
no doc update
Clone Of:
Environment:
Last Closed: 2017-11-28 21:58:09 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github kubernetes kubernetes pull 48145 0 None None None 2017-06-29 15:38:50 UTC
Origin (Github) 14945 0 None None None 2017-06-29 15:37:50 UTC
Red Hat Product Errata RHSA-2017:3188 0 normal SHIPPED_LIVE Moderate: Red Hat OpenShift Container Platform 3.7 security, bug, and enhancement update 2017-11-29 02:34:54 UTC

Description Eric Paris 2017-06-17 04:05:26 UTC 
oc v3.5.5.19

/usr/bin/openshift start master controllers --config=/etc/origin/master/master-config.yaml --loglevel=2 --listen=https://0.0.0.0:8444

Every so often I see stuff like this in the logs. Do I really need to print out every single node in the cluster? Make logs great again.

Jun 16 22:09:34 ip-172-31-54-162.ec2.internal atomic-openshift-master-controllers[48569]: I0616 22:09:34.055664   48569 servicecontroller.go:285] Ensuring LB for service logreceiver/tcpbalancerlog
Jun 16 22:09:34 ip-172-31-54-162.ec2.internal atomic-openshift-master-controllers[48569]: I0616 22:09:34.056275   48569 aws.go:2538] EnsureLoadBalancer(kubernetes, logreceiver, tcpbalancerlog, us-east-1, 172.29.0.1, [{db TCP 6965 {0 6965 } 31109}], [ip-172-31-51-151.ec2.internal ip-172-31-48-24.ec2.internal ip-172-31-61-92.ec2.internal ip-172-31-63-145.ec2.internal ip-172-31-63-137.ec2.internal ip-172-31-55-11.ec2.internal ip-172-31-52-18.ec2.internal ip-172-31-63-87.ec2.internal ip-172-31-61-220.ec2.internal ip-172-31-63-191.ec2.internal ip-172-31-48-241.ec2.internal ip-172-31-55-59.ec2.internal ip-172-31-50-220.ec2.internal ip-172-31-49-138.ec2.internal ip-172-31-51-60.ec2.internal ip-172-31-52-23.ec2.internal ip-172-31-59-158.ec2.internal ip-172-31-60-65.ec2.internal ip-172-31-59-57.ec2.internal ip-172-31-52-2.ec2.internal ip-172-31-53-130.ec2.internal ip-172-31-51-137.ec2.internal ip-172-31-48-190.ec2.internal ip-172-31-58-48.ec2.internal ip-172-31-57-98.ec2.internal ip-172-31-63-184.ec2.internal ip-172-31-61-137.ec2.internal ip-172-31-50-229.ec2.internal ip-172-31-59-69.ec2.internal ip-172-31-51-3.ec2.internal ip-172-31-61-245.ec2.internal ip-172-31-52-98.ec2.internal ip-172-31-59-221.ec2.internal ip-172-31-48-216.ec2.internal ip-172-31-50-164.ec2.internal ip-172-31-58-25.ec2.internal ip-172-31-58-199.ec2.internal ip-172-31-60-76.ec2.internal ip-172-31-57-220.ec2.internal ip-172-31-52-216.ec2.internal ip-172-31-57-97.ec2.internal ip-172-31-57-81.ec2.internal ip-172-31-53-187.ec2.internal ip-172-31-57-9.ec2.internal ip-172-31-55-5.ec2.internal ip-172-31-48-167.ec2.internal ip-172-31-50-88.ec2.internal ip-172-31-55-50.ec2.internal ip-172-31-63-176.ec2.internal ip-172-31-53-253.ec2.internal ip-172-31-62-73.ec2.internal ip-172-31-52-62.ec2.internal ip-172-31-58-166.ec2.internal ip-172-31-58-39.ec2.internal ip-172-31-54-220.ec2.internal ip-172-31-56-64.ec2.internal ip-172-31-55-117.ec2.internal ip-172-31-63-154.ec2.internal ip-172-31-54-162.ec2.internal ip-172-31-63-77.ec2.internal ip-172-31-63-180.ec2.internal ip-172-31-48-114.ec2.internal ip-172-31-53-238.ec2.internal ip-172-31-57-197.ec2.internal i
Jun 16 22:09:34 ip-172-31-54-162.ec2.internal atomic-openshift-master-controllers[48569]: p-172-31-54-155.ec2.internal ip-172-31-53-8.ec2.internal ip-172-31-52-255.ec2.internal ip-172-31-62-204.ec2.internal ip-172-31-57-154.ec2.internal ip-172-31-52-36.ec2.internal ip-172-31-49-140.ec2.internal ip-172-31-54-26.ec2.internal ip-172-31-58-111.ec2.internal ip-172-31-51-187.ec2.internal ip-172-31-57-65.ec2.internal ip-172-31-50-55.ec2.internal ip-172-31-63-13.ec2.internal ip-172-31-62-66.ec2.internal ip-172-31-57-206.ec2.internal ip-172-31-59-250.ec2.internal ip-172-31-57-169.ec2.internal ip-172-31-53-133.ec2.internal ip-172-31-61-142.ec2.internal ip-172-31-57-24.ec2.internal ip-172-31-56-69.ec2.internal ip-172-31-49-206.ec2.internal ip-172-31-51-237.ec2.internal ip-172-31-57-86.ec2.internal ip-172-31-52-239.ec2.internal ip-172-31-51-82.ec2.internal ip-172-31-53-142.ec2.internal ip-172-31-50-149.ec2.internal ip-172-31-59-82.ec2.internal ip-172-31-49-183.ec2.internal ip-172-31-61-58.ec2.internal ip-172-31-53-182.ec2.internal ip-172-31-56-98.ec2.internal ip-172-31-57-41.ec2.internal ip-172-31-57-139.ec2.internal ip-172-31-59-72.ec2.internal ip-172-31-58-87.ec2.internal ip-172-31-61-60.ec2.internal ip-172-31-49-70.ec2.internal ip-172-31-61-162.ec2.internal ip-172-31-56-149.ec2.internal ip-172-31-50-89.ec2.internal ip-172-31-53-47.ec2.internal ip-172-31-53-27.ec2.internal ip-172-31-61-203.ec2.internal ip-172-31-52-126.ec2.internal ip-172-31-62-93.ec2.internal ip-172-31-48-14.ec2.internal ip-172-31-57-102.ec2.internal ip-172-31-55-95.ec2.internal ip-172-31-61-209.ec2.internal ip-172-31-52-194.ec2.internal ip-172-31-60-189.ec2.internal ip-172-31-60-39.ec2.internal ip-172-31-55-29.ec2.internal ip-172-31-53-20.ec2.internal ip-172-31-63-111.ec2.internal ip-172-31-55-214.ec2.internal ip-172-31-61-73.ec2.internal ip-172-31-60-195.ec2.internal ip-172-31-54-30.ec2.internal ip-172-31-62-117.ec2.internal ip-172-31-49-89.ec2.internal ip-172-31-59-253.ec2.internal ip-172-31-55-228.ec2.internal ip-172-31-63-104.ec2.internal ip-172-31-56-204.ec2.internal ip-172-31-58-108.ec2.internal ip-172-31-62-163.ec2.internal ip-172-31-5
Jun 16 22:09:34 ip-172-31-54-162.ec2.internal atomic-openshift-master-controllers[48569]: ternal ip-172-31-55-2.ec2.internal ip-172-31-62-64.ec2.internal ip-172-31-55-86.ec2.internal ip-172-31-49-42.ec2.internal ip-172-31-52-92.ec2.internal ip-172-31-56-76.ec2.internal ip-172-31-48-8.ec2.internal ip-172-31-50-116.ec2.internal ip-172-31-59-231.ec2.internal ip-172-31-54-77.ec2.internal ip-172-31-58-211.ec2.internal ip-172-31-56-184.ec2.internal ip-172-31-61-32.ec2.internal ip-172-31-55-219.ec2.internal ip-172-31-51-63.ec2.internal ip-172-31-62-236.ec2.internal ip-172-31-60-113.ec2.internal ip-172-31-53-190.ec2.internal ip-172-31-58-188.ec2.internal ip-172-31-49-230.ec2.internal ip-172-31-49-20.ec2.internal ip-172-31-59-113.ec2.internal ip-172-31-54-226.ec2.internal ip-172-31-55-14.ec2.internal ip-172-31-52-166.ec2.internal ip-172-31-63-19.ec2.internal ip-172-31-55-15.ec2.internal ip-172-31-62-85.ec2.internal ip-172-31-63-1.ec2.internal ip-172-31-54-67.ec2.internal ip-172-31-49-165.ec2.internal ip-172-31-52-230.ec2.internal ip-172-31-49-220.ec2.internal ip-172-31-52-181.ec2.internal], map[])
Comment 1 Ivan Chavero 2017-06-22 18:09:05 UTC 
(In reply to Eric Paris from comment #0)
> oc v3.5.5.19
> 
> /usr/bin/openshift start master controllers
> --config=/etc/origin/master/master-config.yaml --loglevel=2
> --listen=https://0.0.0.0:8444
> 
> Every so often I see stuff like this in the logs. Do I really need to print
> out every single node in the cluster? Make logs great again.
> 

> Jun 16 22:09:34 ip-172-31-54-162.ec2.internal
> atomic-openshift-master-controllers[48569]: ternal
> ip-172-31-55-2.ec2.internal ip-172-31-62-64.ec2.internal
> ip-172-31-55-86.ec2.internal ip-172-31-49-42.ec2.internal
> ip-172-31-52-92.ec2.internal ip-172-31-56-76.ec2.internal
> ip-172-31-48-8.ec2.internal ip-172-31-50-116.ec2.internal
> ip-172-31-59-231.ec2.internal ip-172-31-54-77.ec2.internal
> ip-172-31-58-211.ec2.internal ip-172-31-56-184.ec2.internal
> ip-172-31-61-32.ec2.internal ip-172-31-55-219.ec2.internal
> ip-172-31-51-63.ec2.internal ip-172-31-62-236.ec2.internal
> ip-172-31-60-113.ec2.internal ip-172-31-53-190.ec2.internal
> ip-172-31-58-188.ec2.internal ip-172-31-49-230.ec2.internal
> ip-172-31-49-20.ec2.internal ip-172-31-59-113.ec2.internal
> ip-172-31-54-226.ec2.internal ip-172-31-55-14.ec2.internal
> ip-172-31-52-166.ec2.internal ip-172-31-63-19.ec2.internal
> ip-172-31-55-15.ec2.internal ip-172-31-62-85.ec2.internal
> ip-172-31-63-1.ec2.internal ip-172-31-54-67.ec2.internal
> ip-172-31-49-165.ec2.internal ip-172-31-52-230.ec2.internal
> ip-172-31-49-220.ec2.internal ip-172-31-52-181.ec2.internal], map[])

can you paste logs with --loglevel=5 please?
Comment 2 Ben Bennett 2017-06-22 19:52:12 UTC 
Ivan, we just need to change these from V(2) to V(4)... but they are in Kubernetes, so you need to post the PR over there and get the change made there.

 $ ack "EnsureLoadBalancer\(" | grep log.V\(2 | grep -v incubator
vendor/k8s.io/kubernetes/pkg/cloudprovider/providers/gce/gce.go:588:	glog.V(2).Infof("EnsureLoadBalancer(%v, %v, %v, %v, %v, %v, %v)", loadBalancerName, gce.region, loadBalancerIP, portStr, hostNames, serviceName, apiService.Annotations)
vendor/k8s.io/kubernetes/pkg/cloudprovider/providers/gce/gce.go:633:			glog.V(2).Infof("EnsureLoadBalancer(%v(%v)): released static IP %s", loadBalancerName, serviceName, ipAddress)
vendor/k8s.io/kubernetes/pkg/cloudprovider/providers/aws/aws.go:2508:	glog.V(2).Infof("EnsureLoadBalancer(%v, %v, %v, %v, %v, %v, %v, %v)",


 $ ack "Ensuring LB for service" | grep -v incubator
vendor/k8s.io/kubernetes/pkg/controller/service/servicecontroller.go:295:		glog.V(2).Infof("Ensuring LB for service %s", key)
Comment 3 Eric Paris 2017-06-22 20:01:43 UTC 
Is this information useful in a normal cluster? What should an admin do with the hundreds and hundreds of nodes being listed regularly? What makes sense to log for everyone? What makes sense to log only in some debug mode? Please fix that upstream and then backport to 3.6.

If this message says nothing useful move it to V(4). If some of it is useful and some of it not, leave the useful part alone and move the rest to V(4)....
Comment 4 Ivan Chavero 2017-06-22 22:39:52 UTC 
(In reply to Ben Bennett from comment #2)
> Ivan, we just need to change these from V(2) to V(4)... but they are in
> Kubernetes, so you need to post the PR over there and get the change made
> there.
> 
>  $ ack "EnsureLoadBalancer\(" | grep log.V\(2 | grep -v incubator
> vendor/k8s.io/kubernetes/pkg/cloudprovider/providers/gce/gce.go:588:
> glog.V(2).Infof("EnsureLoadBalancer(%v, %v, %v, %v, %v, %v, %v)",
> loadBalancerName, gce.region, loadBalancerIP, portStr, hostNames,
> serviceName, apiService.Annotations)
> vendor/k8s.io/kubernetes/pkg/cloudprovider/providers/gce/gce.go:633:		
> glog.V(2).Infof("EnsureLoadBalancer(%v(%v)): released static IP %s",
> loadBalancerName, serviceName, ipAddress)
> vendor/k8s.io/kubernetes/pkg/cloudprovider/providers/aws/aws.go:2508:
> glog.V(2).Infof("EnsureLoadBalancer(%v, %v, %v, %v, %v, %v, %v, %v)",
> 
> 
>  $ ack "Ensuring LB for service" | grep -v incubator
> vendor/k8s.io/kubernetes/pkg/controller/service/servicecontroller.go:295:	
> glog.V(2).Infof("Ensuring LB for service %s", key)

ok, creating patch
Comment 5 Eric Paris 2017-06-27 23:34:28 UTC 
Is there an upstream PR? Can we get it and the origin backport PR linked?
Comment 6 Eric Paris 2017-06-27 23:38:36 UTC 
Upstream PR: https://github.com/kubernetes/kubernetes/pull/48145
Comment 7 Ivan Chavero 2017-06-28 18:11:58 UTC 
This is being addressed on this pull requests:
Upstream: https://github.com/kubernetes/kubernetes/pull/48145
Origin: https://github.com/openshift/origin/pull/14945
Comment 9 zhaozhanqi 2017-09-28 10:09:11 UTC 
Verified this bug on v3.7.0-0.127.0

steps

1. Create ELB env on aws
2. Create Loadbalance service with the following file:
{
      "kind": "Service",
      "apiVersion": "v1",
      "metadata": {
        "name": "example-service"
      },
      "spec": {
        "ports": [{
          "port": 8765,
          "targetPort": 9376
        }],
        "selector": {
          "app": "example"
        },
        "type": "LoadBalancer"
      }
}
3. Check the log on the master:
journalctl -fl | grep -i aws.go
...
...
Sep 28 06:03:24 ip-172-18-12-194.ec2.internal atomic-openshift-master-controllers[42348]: I0928 06:03:24.118359   42348 aws.go:2598] EnsureLoadBalancer(kubernetes, default, example-service, us-east-1, , [{ TCP 8765 {0 9376 } 32030}], map[])
Comment 12 errata-xmlrpc 2017-11-28 21:58:09 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/RHSA-2017:3188
Note You need to log in before you can comment on or make changes to this bug.