istio: Lots of broken pipe messages

Hi,

I see a lot of messages like this ones:

ERROR: logging before flag.Parse: W0121 12:33:25.582797       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:43924: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:28.685612       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:43950: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:28.926268       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44052: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:28.422343       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44496: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:29.604995       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:41466: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:32.603072       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44602: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:32.893017       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44580: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:32.709318       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44578: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:37.218254       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44642: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:38.867804       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44076: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:38.777183       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44700: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:43.155962       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:41060: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:43.890811       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44034: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:44.358863       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44126: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:45.005108       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:43906: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:45.534817       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44842: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:48.605499       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44114: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:48.771415       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44914: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:49.191500       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44124: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:48.478968       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:38184: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:51.281846       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44868: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:52.689080       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44938: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:51.161145       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:43174: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:53.365822       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44958: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:50.854020       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44890: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:56.178188       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44996: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:58.171454       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44072: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:33:57.975179       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:45094: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:00.000635       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:41904: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:01.320217       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:42840: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:02.670353       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:45112: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:03.559636       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44148: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:04.878781       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:45118: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:06.977619       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44092: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:07.475932       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44398: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:10.476942       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44140: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:10.690533       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:45184: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:11.054660       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:45272: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:14.805378       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44260: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:15.875566       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:41334: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:16.758144       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:45522: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:17.875547       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44134: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:18.084283       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44156: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:19.068577       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44504: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:20.782443       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44270: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:21.564345       1 discovery.go:112] Overriding cached data for entry /v1/registration/absolutegrounds-helper-sources.integration-cb.svc.cluster.local%7Chttp-in
ERROR: logging before flag.Parse: W0121 12:34:21.671255       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44324: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:24.753824       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:45856: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:24.869749       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:45952: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:24.871398       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:45938: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:24.961953       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:46004: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:25.772004       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:45982: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:25.965046       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44762: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:27.672164       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:45994: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:28.860328       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:46134: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:29.662173       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44392: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:30.065978       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:46158: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:32.983798       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:46126: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:33.254526       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:46308: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:33.255331       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:46316: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:33.375688       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:46226: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:33.559052       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44164: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:33.778104       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44364: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:34.478453       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44576: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:38.858929       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:46474: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:39.256161       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44574: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:40.772071       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44462: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:40.864003       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44566: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:41.495797       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44530: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:41.571344       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:42030: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:43.375720       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:46634: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:43.380749       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44390: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:43.757054       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:46620: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:44.271456       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44320: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:44.484138       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:46568: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:44.660634       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44760: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:43.185877       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:46718: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:45.272538       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:46530: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:45.760471       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44590: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:46.596645       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:45396: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:47.875895       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:46956: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:47.960908       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:46964: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:48.860727       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:46864: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:49.372279       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:44646: write: broken pipe
ERROR: logging before flag.Parse: W0121 12:34:49.876766       1 discovery.go:590] write tcp 127.0.0.1:8080->127.0.0.1:46866: write: broken pipe

Why all this noise?

Istio: 0.4.0 Kubernetes: 1.8.4

About this issue

Original URL
State: closed
Created 6 years ago
Comments: 24 (22 by maintainers)

Most upvoted comments

It seems the issues I saw were related to someone placing an invalid rule out there editing the notes above to reflect current status.

emaildanwilson on Mar 5, 2018

I managed to get pilot working across all namespaces in our environment finally after making a few tweaks to pilot.

filtered k8s watches for service, endpoint & ingress to look for a specific annotation. We’re adding a specific annotation through our custom injection process.
no-op’d cache updates when a previous request has already updated the cache. Basically return here.
no-op’d cache flushes

I’ll do some additional testing today with the cache flush re-enabled to see if things are still working for us. I think basically what is happening is that pilot waits on the cache mutex so long that the clients have given up before it can respond. Since we have a large number of services, ingresses and endpoints across our cluster there is a constant stream of events and each event updates cache and many cause cache flushes. There is what appears to be a race condition where if the cache record doesn’t exist yet and multiple requests are asking for the same record it will get updated in cache one time for each request (which is quite a lot in a large environment).

Would it make sense for the cache flushes to be key specific?

emaildanwilson on Mar 2, 2018

cc @ldemailly This is the related issue to the heavy cpu usage we are seeing on the injected proxy containers.

emaildanwilson on Jan 24, 2018

a few stats that might help from our setup here. We have istio running in the default istio-system namespace and only a handful of the services running w/ the manually injected proxy.

$kubectl get svc --all-namespaces | wc -l
     445
$kubectl get ingresses --all-namespaces | wc -l
     357
$kubectl get deployments --all-namespaces | wc -l
     536
$kubectl get pods --all-namespaces | wc -l
    1142
$kubectl get endpoints --all-namespaces | wc -l
     449
$kubectl get namespaces | wc -l
     150

What do you think about adding a startup option to pilot so we could filter on an annotation like sidecar.istio.io/inject: "true"? It’s not really practical for a prod setup but might help for dev/test while we are experimenting.

Filtering on a specific --appNamespace isn’t really helpful since I want a high number of teams to experiment in their own namespaces.

emaildanwilson on Jan 23, 2018