Envoy: http connections on tls ports : could use better logging/troubleshooting

[ldemailly]

Context: I spent a lot of time trying to figure out a misconfiguration:
I had an http client making a connection to envoy which was expecting TLS connection

when running with debug logging, one does get the quite clear:
[2017-08-15 17:37:44.057][300][debug][connection] external/envoy/source/common/ssl/connection_impl.cc:151] [C21] SSL error: 268435612:SSL routines:OPENSSL_internal:HTTP_REQUEST
in the log, unfortunately without debug I saw nothing - and on the client side the only thing one sees is a read error/connection closed (with no data)

Ideally as the ssl library correctly identified the request was HTTP it would be nice to return an http error to the client, but...

At least in the default logging level it would be good to surface those bad connections
(with some flood protection so repeated port scanning/bad requests don't fill up the disk/logging system)

Including in the accesslog when the listener is an https one but in general in log as a tcp/tls error

So a first/easy fix would be to just raise the level of the existing logging from debug

Thanks!

ps: more (istio specific) context in https://github.com/istio/pilot/issues/1015

[ldemailly]

this happened again today, @craigbox and I spent several hours debugging what turned out to be a ASN mismatch in certificate that rejected the connection silently

[ldemailly]

this continues to bite customers, users, developers...

[PiotrSikora]

@ldemailly what would be your ideal solution here? Bumping log level to info, so that's visible in the error logs (but I don't think there is a precedent for that) or added as a new flag to %RESPONSE_FLAG% in [access logs]?

[ldemailly]

have it in the access/errror log with some useful / minimal code/message
it's not a "logging" event (though some detailed logging would help) it's a regular failed request

[ldemailly]

ie somesort of 5xx code or 4xx depending why the handshake fails and which side

[ldemailly]

just got another 14 emails back and forth over a day with a user and it turned out to be this issue again... with still nothing in the logs to make a guess that was the issue

[srinandan]

+1 @ldemailly - that user was me :(

I was using Envoy with Istio and assumed I had auto-sidecar injection turned on. There was nothing in the logs that give me this clue.

[ldemailly]

@srinandan : click there:

;-)

[stale[bot]]

This issue has been automatically marked as stale because it has not had activity in the last 30 days. It will be closed in the next 7 days unless it is tagged "help wanted" or other activity occurs. Thank you for your contributions.

[craigbox]

This remains an issue. (/activity)

[cmluciano]

I can work on this but I’m unsure what we settled on. Do we want to just bump the log level or do we want to expose this in the access log?

cc @htuch for feedback

[ldemailly]

it should be imo a 400s or 500s type error clearly indicated in error log and/or access log
ps: it would be sensational to also have the default log include the transport and protocol (tls vs not)

[htuch]

Is this a dupe of https://github.com/envoyproxy/envoy/issues/4283 essentially?

[cmluciano]

On the surface it sounds related, I requested access to that design proposal to clarify. Can someone assign this issue to me?

[mattklein123]

IMO this issue has no concrete ideas on what to actually change. I don't have any high level objection on having better debugging, but I think someone needs to propose an actual change. I will remark this design proposal.

[htuch]

@mattklein123 AFAICT, we want to mark this dupe of #4283 and leave a note there that we should also make sure any design correctly captures SSL failure details.

[mattklein123]

@htuch sure that's fine with me, though I'm not sure that is what @ldemailly was originally after here.

[ldemailly]

well as long as you can tell with the default config that an incoming connection was rejected and why, it will be fantastic, how that happens doesn't matter to me.

[htuch]

OK, continuing tracking at https://github.com/envoyproxy/envoy/issues/4283.

[vilobhmm]

@mattklein123 @htuch @ldemailly : The doc is shared here https://docs.google.com/document/d/1fMEK80KlpHcL4CwhniOupgQu4MDsxK4y4dKhthjjCMA/edit and also shared with Envoy community. I will amend the doc to add the scenario that @ldemailly is describing. Thanks!