Feature: io package provides streaming facility for request and response filters #2428

szuecs · 2023-06-28T20:59:51Z

Feature: io.InspectReader provides streaming facility for request and response filters
feature: logBody() request and response filters
refactor: blockContent() and blockContentHex() filters use the new io.InspectReader

This PR state is only done for the log stream read filters.

should fix #2605

Write stream is out of scope and should be done later.

net/httpbody.go

szuecs · 2023-06-30T15:36:22Z

My first test of readwrite body ported compress() to the new one, right now only for checking the API.

Because I did not change much, no serious change in the benchmark.

% benchstat old new                                  feature/log-body-filters goos: linux
goarch: amd64
pkg: github.com/zalando/skipper/filters/builtin
cpu: AMD Ryzen 7 PRO 4750U with Radeon Graphics
                   │     old      │                new                 │
                   │    sec/op    │   sec/op     vs base               │
CompressGzip0-16     3.855µ ±  5%   3.632µ ± 7%  -5.80% (p=0.001 n=10)
CompressGzip2-16     6.089µ ±  4%   5.919µ ± 1%  -2.79% (p=0.000 n=10)
CompressGzip4-16     27.78µ ±  7%   26.21µ ± 3%  -5.65% (p=0.000 n=10)
CompressGzip6-16     1.742m ±  5%   1.614m ± 2%  -7.34% (p=0.000 n=10)
CompressGzip8-16      1.071 ±  2%    1.043 ± 2%  -2.54% (p=0.002 n=10)
CompressBrotli0-16   4.445µ ±  4%   4.342µ ± 5%  -2.33% (p=0.001 n=10)
CompressBrotli2-16   6.792µ ±  1%   6.826µ ± 2%       ~ (p=0.247 n=10)
CompressBrotli4-16   28.77µ ±  3%   30.25µ ± 3%  +5.16% (p=0.000 n=10)
CompressBrotli6-16   1.724m ±  1%   1.663m ± 4%  -3.55% (p=0.005 n=10)
CompressBrotli8-16   537.4m ± 88%   526.2m ± 5%       ~ (p=0.280 n=10)
geomean              250.6µ         243.9µ       -2.70%

                   │     old      │                 new                 │
                   │     B/op     │     B/op      vs base               │
CompressGzip0-16     17.91Ki ± 1%   18.12Ki ± 1%  +1.20% (p=0.000 n=10)
CompressGzip2-16     19.11Ki ± 2%   19.25Ki ± 2%       ~ (p=0.052 n=10)
CompressGzip4-16     62.80Ki ± 1%   63.17Ki ± 1%  +0.59% (p=0.029 n=10)
CompressGzip6-16     5.044Mi ± 0%   5.049Mi ± 0%       ~ (p=0.315 n=10)
CompressGzip8-16     587.3Mi ± 0%   587.9Mi ± 0%       ~ (p=0.305 n=10)
CompressBrotli0-16   15.79Ki ± 0%   15.81Ki ± 0%  +0.10% (p=0.000 n=10)
CompressBrotli2-16   15.84Ki ± 0%   15.86Ki ± 0%  +0.11% (p=0.000 n=10)
CompressBrotli4-16   61.25Ki ± 0%   61.05Ki ± 0%  -0.33% (p=0.000 n=10)
CompressBrotli6-16   5.030Mi ± 0%   5.029Mi ± 0%       ~ (p=0.075 n=10)
CompressBrotli8-16   587.0Mi ± 0%   587.0Mi ± 0%       ~ (p=0.143 n=10)
geomean              562.4Ki        563.9Ki       +0.25%

                   │     old     │                new                │
                   │  allocs/op  │ allocs/op   vs base               │
CompressGzip0-16     32.00 ±  0%   33.00 ± 0%  +3.12% (p=0.000 n=10)
CompressGzip2-16     32.00 ±  0%   33.00 ± 0%  +3.12% (p=0.000 n=10)
CompressGzip4-16     41.00 ±  0%   42.00 ± 0%  +2.44% (p=0.000 n=10)
CompressGzip6-16     58.00 ±  2%   59.00 ± 2%  +1.72% (p=0.001 n=10)
CompressGzip8-16     147.0 ± 10%   144.5 ± 7%       ~ (p=0.305 n=10)
CompressBrotli0-16   29.00 ±  0%   30.00 ± 0%  +3.45% (p=0.000 n=10)
CompressBrotli2-16   29.00 ±  0%   30.00 ± 0%  +3.45% (p=0.000 n=10)
CompressBrotli4-16   38.00 ±  0%   39.00 ± 0%  +2.63% (p=0.000 n=10)
CompressBrotli6-16   62.00 ±  2%   62.00 ± 2%       ~ (p=0.638 n=10)
CompressBrotli8-16   195.5 ±  4%   194.5 ± 3%       ~ (p=0.781 n=10)
geomean              51.78         52.69       +1.76%

szuecs · 2023-09-20T17:44:48Z

The blockContent() rewrite benchmark shows good enough results:

goos: linux
goarch: amd64
pkg: github.com/zalando/skipper/net
cpu: AMD Ryzen 7 PRO 4750U with Radeon Graphics
                                        │     old.txt     │                new.txt                 │
                                        │     sec/op      │     sec/op      vs base                │
Block/Small_Stream_without_blocking-16       204.8µ ±  0%      206.5µ ± 2%   +0.82% (p=0.002 n=10)
Block/Small_Stream_with_blocking-16       0.002586n ±  6%   0.002402n ± 7%   -7.13% (p=0.002 n=10)
Block/Medium_Stream_without_blocking-16      3.645m ±  0%      3.643m ± 1%        ~ (p=0.739 n=10)
Block/Medium_Stream_with_blocking-16       0.01335n ±  5%    0.01335n ± 5%        ~ (p=0.810 n=10)
Block/Large_Stream_without_blocking-16       32.33m ± 11%      31.50m ± 0%   -2.57% (p=0.000 n=10)
Block/Large_Stream_with_blocking-16        0.09532n ± 10%    0.08548n ± 3%  -10.32% (p=0.002 n=10)
HostPatchCommon-16                                             19.31n ± 2%
HostPatchUncommon-16                                           120.1n ± 6%
RemoteHost-16                                                  199.6n ± 4%
RemoteHostFromLast-16                                          265.8n ± 2%
MatchesRequest-16                                              1.016µ ± 1%
geomean                                      207.3n            183.9n        -3.30%

                                        │    old.txt     │                new.txt                 │
                                        │      B/op      │     B/op       vs base                 │
Block/Small_Stream_without_blocking-16    1.406Ki ± 5%     1.416Ki ± 20%  +0.66% (p=0.037 n=10)
Block/Small_Stream_with_blocking-16         0.000 ± 0%       0.000 ±  0%       ~ (p=1.000 n=10) ¹
Block/Medium_Stream_without_blocking-16   133.2Ki ± 0%     133.0Ki ±  2%       ~ (p=0.358 n=10)
Block/Medium_Stream_with_blocking-16        0.000 ± 0%       0.000 ±  0%       ~ (p=1.000 n=10) ¹
Block/Large_Stream_without_blocking-16    7.361Mi ± 9%     7.162Mi ±  3%  -2.70% (p=0.033 n=10)
Block/Large_Stream_with_blocking-16         0.000 ± 0%       0.000 ±  0%       ~ (p=1.000 n=10) ¹
HostPatchCommon-16                                           0.000 ±  0%
HostPatchUncommon-16                                         16.00 ±  0%
RemoteHost-16                                                48.00 ±  0%
RemoteHostFromLast-16                                        64.00 ±  0%
MatchesRequest-16                                            0.000 ±  0%
geomean                                                ²                  -0.37%                ²
¹ all samples are equal
² summaries must be >0 to compute geomean

                                        │   old.txt    │               new.txt               │
                                        │  allocs/op   │ allocs/op   vs base                 │
Block/Small_Stream_without_blocking-16    0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
Block/Small_Stream_with_blocking-16       0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
Block/Medium_Stream_without_blocking-16   0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
Block/Medium_Stream_with_blocking-16      0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
Block/Large_Stream_without_blocking-16    0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10)
Block/Large_Stream_with_blocking-16       0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
HostPatchCommon-16                                       0.000 ± 0%
HostPatchUncommon-16                                     1.000 ± 0%
RemoteHost-16                                            2.000 ± 0%
RemoteHostFromLast-16                                    3.000 ± 0%
MatchesRequest-16                                        0.000 ± 0%
geomean                                              ²               +0.00%                ²
¹ all samples are equal
² summaries must be >0 to compute geomean

szuecs · 2023-11-21T14:15:48Z

net/httpbody.go

+			return consumedInput, err
+		}
+		if err2 != nil {
+			return consumedInput, err


What error to return here: err, because it's propagating state of Read or err2 because it is what happened at the Write?

szuecs · 2023-11-21T14:31:19Z

Benchmark for "blocking" case

% go test -bench 'BenchmarkBlock/.*blocking$' -benchmem ./net/httpbody*.go -count 10 | tee -a new
% go test -bench 'BenchmarkBlock/.*blocking$' -benchmem ./filters/block -count 10 | tee -a old


% benchstat old new
goos: linux
goarch: amd64
cpu: AMD Ryzen 7 PRO 4750U with Radeon Graphics
                                        │        old         │                   new                    │
                                        │       sec/op       │     sec/op       vs base                 │
Block/Small_Stream_without_blocking-16      205408.50n ±  1%      50.16n ±  3%   -99.98% (p=0.000 n=10)
Block/Small_Stream_with_blocking-16          0.002864n ±  5%   0.003645n ± 21%   +27.29% (p=0.000 n=10)
Block/Medium_Stream_without_blocking-16    3740466.50n ±  3%      49.43n ±  2%  -100.00% (p=0.000 n=10)
Block/Medium_Stream_with_blocking-16          0.01483n ± 10%    0.01497n ±  2%         ~ (p=0.393 n=10)
Block/Large_Stream_without_blocking-16    33275855.00n ±  0%      53.78n ±  4%  -100.00% (p=0.000 n=10)
Block/Large_Stream_with_blocking-16           0.09773n ±  9%    0.09437n ±  5%    -3.43% (p=0.029 n=10)
geomean                                         217.6n           0.9393n         -99.57%

                                        │        old        │                    new                    │
                                        │       B/op        │     B/op      vs base                     │
Block/Small_Stream_without_blocking-16       1.411Ki ± 1%     0.000Ki ± 0%  -100.00% (p=0.000 n=10)
Block/Small_Stream_with_blocking-16            0.000 ± 0%       0.000 ± 0%         ~ (p=1.000 n=10) ¹
Block/Medium_Stream_without_blocking-16   140230.500 ± 7%       1.000 ± 0%  -100.00% (p=0.000 n=10)
Block/Medium_Stream_with_blocking-16           0.000 ± 0%       0.000 ± 0%         ~ (p=1.000 n=10) ¹
Block/Large_Stream_without_blocking-16    8172572.00 ± 0%       13.00 ± 8%  -100.00% (p=0.000 n=10)
Block/Large_Stream_with_blocking-16            0.000 ± 0%       0.000 ± 0%         ~ (p=1.000 n=10) ¹
geomean                                                   ²                 ?                       ² ³
¹ all samples are equal
² summaries must be >0 to compute geomean
³ ratios must be >0 to compute geomean  

                                        │     old      │                 new                 │
                                        │  allocs/op   │ allocs/op   vs base                 │
Block/Small_Stream_without_blocking-16    0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
Block/Small_Stream_with_blocking-16       0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
Block/Medium_Stream_without_blocking-16   0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
Block/Medium_Stream_with_blocking-16      0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
Block/Large_Stream_without_blocking-16    0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
Block/Large_Stream_with_blocking-16       0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
geomean                                              ²               +0.00%                ²
¹ all samples are equal
² summaries must be >0 to compute geomean

filters/block/block.go

AlexanderYastrebov · 2024-01-05T09:33:44Z

filters/block/block_test.go

+		args := []interface{}{"foo"}
+		args2 := []interface{}{"bar"}
+		r := &eskip.Route{Filters: []*eskip.Filter{
+			{Name: spec.Name(), Args: args},
+			{Name: spec.Name(), Args: args2},
+		}, Backend: backend.URL}


I think eskip.MustParse* would be more readable here.

No it won't, because of parameters and args will be ugly to put

filters/block/block_test.go

filters/diag/logbody.go

AlexanderYastrebov · 2024-01-05T09:41:19Z

net/httpbody.go

+func (m *matcher) Close() error {
+	var err error
+	m.once.Do(func() {
+		m.closed = true
+		if c, ok := m.input.(io.Closer); ok {
+			err = c.Close()
+		}
+	})
+	return err
+}


Second call to Close will return nil.

net/httpbody.go

AlexanderYastrebov · 2024-01-05T10:02:17Z

net/httpbody.go

+func LogBody(ctx context.Context, fmtstr string, log func(format string, args ...interface{}), rc io.ReadCloser) io.ReadCloser {
+	return newLogBody(ctx, fmtstr, log, rc)
+}


It looks like a simple Reader wrapper. Why do we need it in net package?

It also does not look related to WrapBody so maybe add it in a separate PR?

It was your suggestion to add it separately from WrapBody.
I think the feature makes sense to have here, because it's usable as it is without dependency to filters for example.

szuecs · 2024-01-05T10:48:32Z

filters/block/matcher.go

-
-	for _, s := range m.toblockList {
-		if bytes.Contains(b, s.str) {
-			b = nil


copied from here

feature: implement net.HttpBody to allow streaming filters on http body request and response refactoring: blockContent,blockContentHex filters to use the new implementation refactor: move ErrBlock form proxy to net refactor: reuse types and enum and expose options to set httpbody matcher config drop noleak because of transport related leaks feature: read write body wrapper and test api with porting compress filter Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

…at it can be searched in log analysis Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

rename: error should not tell "body" but "stream" Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

rename BodyOptions to BufferOptions Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

szuecs · 2024-01-05T13:30:07Z

Closing in favor of a PR split into:

szuecs added the wip work in progress label Jun 28, 2023

szuecs commented Jun 28, 2023

View reviewed changes

net/httpbody.go Outdated Show resolved Hide resolved

szuecs commented Jun 28, 2023

View reviewed changes

net/httpbody.go Outdated Show resolved Hide resolved

szuecs mentioned this pull request Aug 11, 2023

encoder/decode streaming filters #2512

Open

szuecs mentioned this pull request Aug 21, 2023

OPA: authorization based on request body #2518

Merged

szuecs force-pushed the feature/log-body-filters branch from b5c4004 to a4a1e26 Compare August 22, 2023 17:06

szuecs force-pushed the feature/log-body-filters branch 2 times, most recently from 1d04fd9 to 5fc019f Compare September 20, 2023 10:27

szuecs mentioned this pull request Nov 16, 2023

Filters: logBody("request", "response") #2282

Closed

trkohler mentioned this pull request Nov 17, 2023

Filter: logBody("request", "response") #2741

Closed

szuecs force-pushed the feature/log-body-filters branch 2 times, most recently from 6d94e05 to e014a1c Compare November 20, 2023 21:55

szuecs commented Nov 21, 2023

View reviewed changes

szuecs force-pushed the feature/log-body-filters branch from e014a1c to c6c0c7d Compare November 22, 2023 15:56

szuecs added ready-for-review and removed wip work in progress labels Nov 28, 2023

szuecs requested a review from AlexanderYastrebov November 28, 2023 20:47

szuecs added the architectural all changes in the hot path, big changes in the control plane, control flow changes in filters label Dec 22, 2023

AlexanderYastrebov reviewed Jan 5, 2024

View reviewed changes

szuecs commented Jan 5, 2024

View reviewed changes

filters/block/matcher.go

for _, s := range m.toblockList {

if bytes.Contains(b, s.str) {

b = nil

Copy link

Member Author

szuecs Jan 5, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

copied from here

szuecs changed the title ~~Feature: net.WrapBody provides streaming facility for request and response filters~~ Feature: io package provides streaming facility for request and response filters Jan 5, 2024

szuecs force-pushed the feature/log-body-filters branch from ed9bc61 to f4366a9 Compare January 5, 2024 12:59

szuecs added 5 commits January 5, 2024 14:03

optimize logBody to not buffer and pass x-flow-id to the log, such th…

9e5341f

…at it can be searched in log analysis Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

fix: pass req.Context() instead of background context

ac9dbda

Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

delete unused

40b77ef

Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

move metrics from matcher to filter

2a3ff28

Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

szuecs added 8 commits January 5, 2024 14:03

refactor: remove WrapBody

b20055d

Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

refactor: move stream body code from net/ to io/

e9bb80f

Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

refactor: split io pkg into multiple files

cc86397

Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

cleanup

a16181a

rename: error should not tell "body" but "stream" Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

nop: drop unrelated changes from PR

7b9ba4d

Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

refactor: use proxy.URL as valid url

4a82be4

Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

rename WrapBodyWithOptions to InspectReader

f225318

rename BodyOptions to BufferOptions Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

fix: remove b=nil setting which does not do anything

a56cb3d

Signed-off-by: Sandor Szücs <sandor.szuecs@zalando.de>

szuecs force-pushed the feature/log-body-filters branch from f4366a9 to a56cb3d Compare January 5, 2024 13:03

This was referenced Jan 5, 2024

feature: logBody filter #2827

Merged

feature: io package inspect stream reader #2828

Merged

szuecs closed this Jan 5, 2024

szuecs deleted the feature/log-body-filters branch January 5, 2024 13:39

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Feature: io package provides streaming facility for request and response filters #2428

Feature: io package provides streaming facility for request and response filters #2428

szuecs commented Jun 28, 2023 •

edited

Loading

szuecs commented Jun 30, 2023

szuecs commented Sep 20, 2023 •

edited

Loading

szuecs Nov 21, 2023

szuecs commented Nov 21, 2023

AlexanderYastrebov Jan 5, 2024

szuecs Jan 5, 2024

AlexanderYastrebov Jan 5, 2024

szuecs Jan 5, 2024

AlexanderYastrebov Jan 5, 2024

AlexanderYastrebov Jan 5, 2024

szuecs Jan 5, 2024 •

edited

Loading

szuecs Jan 5, 2024

szuecs commented Jan 5, 2024

Feature: io package provides streaming facility for request and response filters #2428

Feature: io package provides streaming facility for request and response filters #2428

Conversation

szuecs commented Jun 28, 2023 • edited Loading

szuecs commented Jun 30, 2023

szuecs commented Sep 20, 2023 • edited Loading

Choose a reason for hiding this comment

szuecs commented Nov 21, 2023

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

szuecs Jan 5, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

szuecs commented Jan 5, 2024

szuecs commented Jun 28, 2023 •

edited

Loading

szuecs commented Sep 20, 2023 •

edited

Loading

szuecs Jan 5, 2024 •

edited

Loading