[PATCH] [nginx-tests] Tests: Add sleep to sub_filter_multi.t for TEST_NGINX_UNSAFE=1

[Hiroaki Nakamura]

Hello,

Thank you for your thorough explanation.
I have confirmed that your patch works for me.

Best regards,
Hiroaki Nakamura

2024年6月20日(木) 9:51 Maxim Dounin <mdounin at mdounin.ru>:

>
> Hello!
>
> On Wed, Jun 19, 2024 at 07:15:53AM +0900, Hiroaki Nakamura wrote:
>
> > # HG changeset patch
> > # User Hiroaki Nakamura <hnakamur at gmail.com>
> > # Date 1718746554 -32400
> > #      Wed Jun 19 06:35:54 2024 +0900
> > # Node ID 8d9e1bc9721896618b0bb4095e39be46ca8fc280
> > # Parent  a095b971fbcc99a77206173f6130d5ff2681c389
> > Add sleep to sub_filter_multi for NGINX_TEST_UNSAFE=1
> >
> > Without this fix, sub_filter_multi.t fails like below:
> > ```
> > $ sudo -u nginx TEST_NGINX_UNSAFE=1
> > TEST_NGINX_BINARY=../freenginx/objs/nginx prove sub_filter_multi.t
> > sub_filter_multi.t .. 37/44
> > #   Failed test 'shortbuf match 1.3'
> > #   at sub_filter_multi.t line 366.
> > #                   undef
> > #     doesn't match '(?^:(+ABCDE){3})'
> > sub_filter_multi.t .. 42/44
> > #   Failed test 'shortbuf match 5'
> > #   at sub_filter_multi.t line 376.
> > #                   undef
> > #     doesn't match '(?^:+ABCDE(-*nyABCDE){2})'
> > # Looks like you failed 2 tests of 44.
> > sub_filter_multi.t .. Dubious, test returned 2 (wstat 512, 0x200)
> > Failed 2/44 subtests
> > ```
> >
> > diff -r a095b971fbcc -r 8d9e1bc97218 sub_filter_multi.t
> > --- a/sub_filter_multi.t        Tue Jun 04 18:38:01 2024 +0300
> > +++ b/sub_filter_multi.t        Wed Jun 19 06:35:54 2024 +0900
> > @@ -363,8 +363,8 @@
> >         qr/(+A){3}/, 'shortbuf match 1.1');
> >  like(http_get('/shortbuf/match1?a=' . 'abpatternyzABCD' x 3),
> >         qr/(+ABCD){3}/, 'shortbuf match 1.2');
> > -like(http_get('/shortbuf/match1?a=' . 'abpatternyzABCDE' x 3),
> > -       qr/(+ABCDE){3}/, 'shortbuf match 1.3');
> > +like(http_get('/shortbuf/match1?a=' . 'abpatternyzABCDE' x 3, sleep => 1),
> > +               qr/(+ABCDE){3}/, 'shortbuf match 1.3');
> >  like(http_get('/shortbuf/match2?a=' . 'abpatternyzAabpaernyzB' x 2),
> >         qr/(+A-B){2}/, 'shortbuf match 2.1 (multiple replace)');
> >  like(http_get('/shortbuf/match2?a=' . 'abpatternyzAabpaernyz' x 2),
> > @@ -373,7 +373,7 @@
> >         qr/(+A*){3}/, 'shortbuf match 3 (1 byte search pattern)');
> >  like(http_get('/shortbuf/match4?a=' . 'pattABCDEFGHI' x 3),
> >         qr/(+ABCDEFGHI){3}/, 'shortbuf match 4');
> > -like(http_get('/shortbuf/match5?a=abpatternyzABCDE' . 'abpatternyABCDE' x 2),
> > +like(http_get('/shortbuf/match5?a=abpatternyzABCDE' .
> > 'abpatternyABCDE' x 2, sleep => 1),
> >         qr/+ABCDE(-*nyABCDE){2}/, 'shortbuf match 5');
> >  }
>
> Thanks for the patch.
>
> Using the "sleep" option looks wrong to me: it is designed to
> introduce a pause before sending the request body, and such a
> pause is not needed in these tests.
>
> Instead, test failures you are seeing seems to be a result of the
> fact that tests in question take a lot of time, and http_get()
> times out while waiting for responses.
>
> Overall, it looks like the tests are suboptimal and very fragile:
> they use "limit_rate 4; limit_rate_after 160;" on the upstream
> server, which results in 1 second response time for each 4
> bytes (over 164 bytes which are sent initially).  For example, the
> "shortbuf match 5" test, currently results in 147 bytes of
> the response headers and uses 46 bytes of the response body, so
> the last response byte is sent after 8 seconds - which is exactly
> the timeout value http_get() uses.  As such, the test is highly
> likely to fail.
>
> Most likely, the test took slightly less time when it was
> initially written due to slightly shorter response headers, and
> therefore used to succeed.  Accordingly, a quick fix would be to
> use a larger limit_rate_after value, such as 165 or 170.
>
> A better fix would be to rewrite all these tests with embedded
> Perl, similarly to how it is done in sub_filter_perl.t, so
> multiple buffers will be generated without any unneeded delays.
> This will make the tests much more robust and much faster.  Not
> sure it worth the effort though, especially given that these tests
> are under TEST_NGINX_UNSAFE and thus not really expected to be run
> automatically.
>
> Below is a patch to bump limit_rate_after to 170, please take a
> look if it works for you:
>
> # HG changeset patch
> # User Maxim Dounin <mdounin at mdounin.ru>
> # Date 1718843281 -10800
> #      Thu Jun 20 03:28:01 2024 +0300
> # Node ID 9ed5047551e7455353d61c3b7e955e959a594050
> # Parent  a095b971fbcc99a77206173f6130d5ff2681c389
> Tests: adjusted sub_filter_multi.t limit rate settings.
>
> With previous settings some tests with short buffers, which are under
> TEST_NGINX_UNSAFE, used to hit 8 seconds timeout in http_get(), leading
> to test failures.
>
> Reported by Hiroaki Nakamura,
> https://freenginx.org/pipermail/nginx-devel/2024-June/000373.html
>
> diff --git a/sub_filter_multi.t b/sub_filter_multi.t
> --- a/sub_filter_multi.t
> +++ b/sub_filter_multi.t
> @@ -244,7 +244,7 @@ http {
>          listen       127.0.0.1:8081;
>
>          limit_rate 4;
> -        limit_rate_after 160;
> +        limit_rate_after 170;
>
>          location / {
>              return 200 $arg_a;
>
>
> --
> Maxim Dounin
> http://mdounin.ru/