Better logging message on header count exceeded by plallin · Pull Request #14915 · envoyproxy/envoy

plallin · 2021-02-02T18:24:59Z

Signed-off-by: Pauline pauline.lallinec@gmail.com

For an explanation of how to fill out the fields, please see the relevant section
in PULL_REQUESTS.md

Commit Message: Better error message on header count exceeded
Additional Description: The header size and header count limit exceeded is the same message "header size exceeded". This PR clarifies the case when header count is exceeded.
Risk Level: low
Testing: unit tests updated
Docs Changes: n/a
Release Notes: n/a
Platform Specific Features: n/a

Signed-off-by: Pauline <pauline.lallinec@gmail.com>

asraa

Change looks good to me! Let me know about that note, otherwise LGTM

asraa · 2021-02-02T20:17:21Z

source/common/http/http1/codec_impl.cc

    const absl::string_view header_type =
        processing_trailers_ ? Http1HeaderTypes::get().Trailers : Http1HeaderTypes::get().Headers;
-    return codecProtocolError(absl::StrCat(header_type, " size exceeds limit"));
+    return codecProtocolError(absl::StrCat(header_type, " count exceeds limit"));


does this suffice for your use case? if you want the difference to show up in the response (as opposed to details in logging), error_code_ will be the response body. right now it is Http::Code::RequestHeaderFieldsTooLarge for both.

That's an excellent remark. My use case is not on requests, though, it's for responses. Where we had a response from a server sending a whooping 116 headers, the error in Envoy showed up as (1) headers disconnect before response and (2) 503 Upstream Disconnect.

Only by increasing logging we could figure out that there were too many headers in the response, causing Envoy to terminate the connection.

Ah! Thanks for the clarification.

Signed-off-by: Pauline <pauline.lallinec@gmail.com>

asraa · 2021-02-03T20:29:14Z

Could you please fix format? Otherwise LGTM
/wait

plallin · 2021-02-03T21:21:10Z

@asraa ty; I have failing tests I need to fix; I've not been able to execute them locally yet and the test runner provided doesn't give much details as to why they're failing. I'll need to get back to it this week-end...

Signed-off-by: Pauline <pauline.lallinec@gmail.com>

plallin · 2021-02-04T10:30:05Z

@asraa I ?think? the tests passed. Can you help me check whether the failures in the pipeline are related?

I see 2 of them

2021-02-04T00:14:31.2653668Z spawn docker run --rm -ti --network=host solsson/websocat ws://localhost:10000
2021-02-04T00:14:31.5161823Z websocat: WebSocketError: I/O failure
2021-02-04T00:14:31.5166642Z websocat: error running

and

2021-02-03T23:23:18.4723173Z FAILED: //test/extensions/filters/http/grpc_json_transcoder:grpc_json_transcoder_integration_test (Summary)
2021-02-03T23:23:18.4726022Z       C:/build/tmp/execroot/envoy/bazel-out/x64_windows-opt/testlogs/test/extensions/filters/http/grpc_json_transcoder/grpc_json_transcoder_integration_test/test.log
2021-02-03T23:23:18.4732019Z       C:/build/tmp/execroot/envoy/bazel-out/x64_windows-opt/testlogs/test/extensions/filters/http/grpc_json_transcoder/grpc_json_transcoder_integration_test/test_attempts/attempt_1.log

Meanwhile the test I updated passed:

2021-02-03T23:28:57.3100752Z //test/common/http/http1:codec_impl_test                                 PASSED in 8.4s

and the grpc_json_transcoder integration test passed in other (non-windows) pipeline:

2021-02-03T23:14:49.9377086Z //test/extensions/filters/http/grpc_json_transcoder:grpc_json_transcoder_integration_test PASSED in 12.8s

(from this pipeline)

If this is unrelated to the current PR, is it possible to re-run the test? [edit: found the kitty command to do it]

If it is related, can you walk me through it? This is my first non-documentation PR in Envoy, please excuse the newbieness :-)

plallin · 2021-02-04T10:31:52Z

/retest

repokitteh-read-only · 2021-02-04T10:31:56Z

Retrying Azure Pipelines:
Retried failed jobs in: envoy-presubmit

🐱

Caused by: a #14915 (comment) was created by @plallin.

see: more, trace.

plallin · 2021-02-04T11:21:00Z

Looking at the failed script, it has had a lot of failures recently with only 1 out of 5 pipeline being successful.

I can see on a successful pipeline, it does:

021-02-02T13:00:09.4506146Z > [tls] Interact with web socket ws -> ws
2021-02-02T13:00:09.6171700Z spawn docker run --rm -ti --network=host solsson/websocat ws://localhost:10000
2021-02-02T13:00:10.6232867Z HELO
2021-02-02T13:00:10.6234284Z [ws] HELO
2021-02-02T13:00:10.6261953Z GOODBYE
2021-02-02T13:00:10.6262718Z [ws] HELO
2021-02-02T13:00:10.6270336Z 
2021-02-02T13:00:10.6272389Z > [tls] Interact with web socket wss -> wss
2021-02-02T13:00:10.6326487Z spawn docker run --rm -ti --network=host solsson/websocat --insecure wss://localhost:20000
2021-02-02T13:00:11.6409889Z HELO
2021-02-02T13:00:11.6421804Z [wss] HELO
2021-02-02T13:00:11.6427319Z GOODBYE
2021-02-02T13:00:11.6436840Z [wss] HELO
2021-02-02T13:00:11.6454191Z 
2021-02-02T13:00:11.6455897Z > [tls] Interact with web socket wss passthrough
2021-02-02T13:00:11.6497882Z spawn docker run --rm -ti --network=host solsson/websocat --insecure wss://localhost:30000
2021-02-02T13:00:12.6591804Z HELO
2021-02-02T13:00:12.6596911Z [wss] HELO
2021-02-02T13:00:12.6601501Z GOODBYE
2021-02-02T13:00:12.6603025Z [wss] HELO
2021-02-02T13:00:12.6694373Z 
2021-02-02T13:00:12.6695740Z > [tls] Cleanup (.)

While on mine and others, it does:

2021-02-04T11:03:38.1149607Z > [tls] Interact with web socket ws -> ws
2021-02-04T11:03:38.3143654Z spawn docker run --rm -ti --network=host solsson/websocat ws://localhost:10000
2021-02-04T11:03:38.5956163Z websocat: WebSocketError: I/O failure
2021-02-04T11:03:38.5957714Z websocat: error running
2021-02-04T11:03:38.5967854Z HELO
2021-02-04T11:03:38.6510123Z send: spawn id exp3 not open
2021-02-04T11:03:38.6511546Z     while executing
2021-02-04T11:03:38.6512455Z "send \x03"
2021-02-04T11:03:38.6542212Z 
2021-02-04T11:03:38.6543324Z > [tls] Cleanup (.)

This seems to be an IO error unrelated to the current work. What can I do about it?

plallin · 2021-02-04T11:23:56Z

/retest

repokitteh-read-only · 2021-02-04T11:23:59Z

Retrying Azure Pipelines:
Retried failed jobs in: envoy-presubmit

🐱

Caused by: a #14915 (comment) was created by @plallin.

see: more, trace.

plallin · 2021-02-04T13:25:41Z

/retest

repokitteh-read-only · 2021-02-04T13:25:45Z

Retrying Azure Pipelines:
Retried failed jobs in: envoy-presubmit

🐱

Caused by: a #14915 (comment) was created by @plallin.

see: more, trace.

asraa · 2021-02-04T13:34:13Z

Hmm thanks @plallin for re-running! I think verify-examples has been flakey, and those are most likely unrelated to your code since it's just the log message changed.

I've not been able to execute them locally yet

For running locally (assuming there's enough space to build), check out https://github.com/envoyproxy/envoy/blob/17e815122ff53d0ac6cb2d64cdbf1bfc547bb7e8/bazel/README.md#testing-envoy-with-bazel once you've gone through the quick start.

I'll keep an eye on verify-examples.

plallin · 2021-02-04T13:39:55Z

@asraa Thanks! I've been able to run the test locally since; unfortunately my personal computer isn't optimised for development and I run into an OOM. I can probably configure Bazel to not use as much memory, but that's a problem for a future PR :-)

I have checked other PRs here, they run in the same issue with verify-examples, see here for example

plallin · 2021-02-04T14:35:31Z

/retest

repokitteh-read-only · 2021-02-04T14:35:35Z

Retrying Azure Pipelines:
Retried failed jobs in: envoy-presubmit

🐱

Caused by: a #14915 (comment) was created by @plallin.

see: more, trace.

…unt-log Signed-off-by: Pauline <pauline.lallinec@gmail.com>

asraa · 2021-02-04T21:22:10Z

Thanks! @envoyproxy/senior-maintainers can you please merge this PR? It changes log messages in the H/1 codec

better logging message on header count exceeded

5efa9f5

Signed-off-by: Pauline <pauline.lallinec@gmail.com>

antoniovicente requested a review from asraa February 2, 2021 18:43

antoniovicente assigned asraa Feb 2, 2021

removed legacy file

01f8613

Signed-off-by: Pauline <pauline.lallinec@gmail.com>

asraa reviewed Feb 2, 2021

View reviewed changes

attempt to fix unit tests

c9f813b

Signed-off-by: Pauline <pauline.lallinec@gmail.com>

repokitteh-read-only bot added the waiting label Feb 3, 2021

formatting

234947b

Signed-off-by: Pauline <pauline.lallinec@gmail.com>

repokitteh-read-only bot removed the waiting label Feb 3, 2021

asraa approved these changes Feb 4, 2021

View reviewed changes

phlax mentioned this pull request Feb 4, 2021

Websocket sandbox test is flakey #14939

Closed

plallin added 2 commits February 4, 2021 15:11

Merge branch 'main' of github.com:envoyproxy/envoy into fix-header-co…

c20dab1

…unt-log Signed-off-by: Pauline <pauline.lallinec@gmail.com>

Merge branch 'main' of github.com:envoyproxy/envoy into fix-header-co…

1f865a5

…unt-log Signed-off-by: Pauline <pauline.lallinec@gmail.com>

snowp merged commit bcf3cdc into envoyproxy:main Feb 4, 2021

Conversation

plallin commented Feb 2, 2021

Uh oh!

asraa left a comment

Choose a reason for hiding this comment

Uh oh!

asraa Feb 2, 2021

Choose a reason for hiding this comment

Uh oh!

plallin Feb 2, 2021

Choose a reason for hiding this comment

Uh oh!

asraa Feb 3, 2021

Choose a reason for hiding this comment

Uh oh!

asraa commented Feb 3, 2021

Uh oh!

plallin commented Feb 3, 2021

Uh oh!

plallin commented Feb 4, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

plallin commented Feb 4, 2021

Uh oh!

repokitteh-read-only bot commented Feb 4, 2021

Uh oh!

plallin commented Feb 4, 2021

Uh oh!

plallin commented Feb 4, 2021

Uh oh!

repokitteh-read-only bot commented Feb 4, 2021

Uh oh!

plallin commented Feb 4, 2021

Uh oh!

repokitteh-read-only bot commented Feb 4, 2021

Uh oh!

asraa commented Feb 4, 2021

Uh oh!

plallin commented Feb 4, 2021

Uh oh!

plallin commented Feb 4, 2021

Uh oh!

repokitteh-read-only bot commented Feb 4, 2021

Uh oh!

asraa commented Feb 4, 2021

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

plallin commented Feb 4, 2021 •

edited

Loading