Re: Current pytest failures
Am 09.03.23 um 11:29 schrieb Stefan Eissing via dev: Am 09.03.2023 um 11:22 schrieb Rainer Jung : Puzzle partially solved: once I add "--header 'content-type: application/x-www-form-urlencoded'" to the nghttp call, the problem seems fixed - with and without deflate. No more hang, no more status 500, no double requests. I still don't know, which side is influenced, nghttp or http, so I am still not sure, whether the odd behavior without the header is a bug. Hmm, never seen that. Is this a current nghttp? Normally, calling "nghttp --data=file" will do all that. I think, since it stabilizes the test, please add the forced content-type header to the test suite. It should do no harm (famous last words), Will do. It happens with nghttp 1.34.0 and recent 1.52.0. I took the header from my curl, which automatically adds it, but I think the right header is Content-Type: multipart/form-data; boundary=DSAJKcd9876 That one is explicitly added in pyhttpd/nghttp.py in function upload_file, but not in post_name. Skimming through the code for nghttp, it seems it dows add content-length (if not forbidden by a commandline flag), but I didn't find an explicit mentioning of content-type. Best regards, Rainer
Re: Current pytest failures
> Am 09.03.2023 um 11:22 schrieb Rainer Jung : > > Puzzle partially solved: once I add "--header 'content-type: > application/x-www-form-urlencoded'" to the nghttp call, the problem seems > fixed - with and without deflate. No more hang, no more status 500, no double > requests. I still don't know, which side is influenced, nghttp or http, so I > am still not sure, whether the odd behavior without the header is a bug. Hmm, never seen that. Is this a current nghttp? Normally, calling "nghttp --data=file" will do all that. I think, since it stabilizes the test, please add the forced content-type header to the test suite. It should do no harm (famous last words), - Stefan > > Am 09.03.23 um 11:03 schrieb Rainer Jung: >> OK, I can test in a standalone situation now. >> The problem goes away, once I use curl, even with h2. >> The problem also goes away, once I disable deflate compression for the >> response. But curl and nghttp behave different: nghttp hangs after receiving >> the response body (no deflate), curl normally terminates. nghttp does not >> hang if I call some normal production site. >> Will investigate further. >> Thanks and regards, >> Rainer
Re: Current pytest failures
Puzzle partially solved: once I add "--header 'content-type: application/x-www-form-urlencoded'" to the nghttp call, the problem seems fixed - with and without deflate. No more hang, no more status 500, no double requests. I still don't know, which side is influenced, nghttp or http, so I am still not sure, whether the odd behavior without the header is a bug. Am 09.03.23 um 11:03 schrieb Rainer Jung: OK, I can test in a standalone situation now. The problem goes away, once I use curl, even with h2. The problem also goes away, once I disable deflate compression for the response. But curl and nghttp behave different: nghttp hangs after receiving the response body (no deflate), curl normally terminates. nghttp does not hang if I call some normal production site. Will investigate further. Thanks and regards, Rainer
Re: Current pytest failures
OK, I can test in a standalone situation now. The problem goes away, once I use curl, even with h2. The problem also goes away, once I disable deflate compression for the response. But curl and nghttp behave different: nghttp hangs after receiving the response body (no deflate), curl normally terminates. nghttp does not hang if I call some normal production site. Will investigate further. Thanks and regards, Rainer
Re: Current pytest failures
I will see how to extract the test case out of pytest to be able to run it standalone and vary the protocol. But the connection reset plus second request might also be nghttp specific. I will also try running nghttp from remote and sniff to double check the connection reset plus second request. Thanks and regards, Rainer Am 09.03.23 um 09:19 schrieb Ruediger Pluem: On 3/8/23 10:44 PM, Rainer Jung wrote: Hi there, I currently get three consistent pytest failures: Do A) and B) work if you do the requests via HTTP/1.1? Regards Rüdiger
Re: Current pytest failures
Thanks for the tip. I already did the "run only one test case" and I fixed the LogLevel in test.conf to include trace8. So I guess there will not be any additional CGI logging available. But good to know the "-vvv". Thanks and regards, Rainer Am 09.03.23 um 09:33 schrieb Stefan Eissing via dev: One tip, if you call "pytest -vvv -k test_h2_202_03b", it will run just that test and raise LogLevel for several "interesting" modules. The error log in test/gen/apache/logs/error_log will then show just that one test case. It's a convenient way to get more information without meddling with the test case configs. The list of modules for which the log level is raised on "-vvv" is found in test/modules/http2/env.py:73 self.add_httpd_log_modules(["http2", "proxy_http2", "h2test", "proxy", "proxy_http"]) we can add "cgi" or others if those are of interest.
Re: Current pytest failures
One tip, if you call "pytest -vvv -k test_h2_202_03b", it will run just that test and raise LogLevel for several "interesting" modules. The error log in test/gen/apache/logs/error_log will then show just that one test case. It's a convenient way to get more information without meddling with the test case configs. The list of modules for which the log level is raised on "-vvv" is found in test/modules/http2/env.py:73 self.add_httpd_log_modules(["http2", "proxy_http2", "h2test", "proxy", "proxy_http"]) we can add "cgi" or others if those are of interest. > Am 08.03.2023 um 22:44 schrieb Rainer Jung : > > Hi there, > > I currently get three consistent pytest failures: > > > A) FAILED modules/http2/test_202_trailer.py::TestTrailers::test_h2_202_03b > > Response code is 500 and trace 8 server log shows: > > - we see the right request > > [Wed Mar 08 22:03:35.699234 2023] [aptest:info] [pid 4606:tid > 140645737559808] [remote 127.0.0.1:50490] test[test_h2_202_03b]: POST > //echohd.py?name=X HTTP/2.0 > [Wed Mar 08 22:03:35.699247 2023] [http:trace4] [pid 4606:tid > 140645737559808] http_request.c(436): [remote 127.0.0.1:50490] Headers > received from client: > [Wed Mar 08 22:03:35.699254 2023] [http:trace4] [pid 4606:tid > 140645737559808] http_request.c(440): [remote 127.0.0.1:50490] Accept: */* > [Wed Mar 08 22:03:35.699259 2023] [http:trace4] [pid 4606:tid > 140645737559808] http_request.c(440): [remote 127.0.0.1:50490] > Accept-Encoding: gzip, deflate > [Wed Mar 08 22:03:35.699264 2023] [http:trace4] [pid 4606:tid > 140645737559808] http_request.c(440): [remote 127.0.0.1:50490] User-Agent: > nghttp2/1.52.0 > [Wed Mar 08 22:03:35.699268 2023] [http:trace4] [pid 4606:tid > 140645737559808] http_request.c(440): [remote 127.0.0.1:50490] > Content-Length: 119 > [Wed Mar 08 22:03:35.699273 2023] [http:trace4] [pid 4606:tid > 140645737559808] http_request.c(440): [remote 127.0.0.1:50490] Host: > 127.0.0.1:5001 > [Wed Mar 08 22:03:35.699277 2023] [http:trace4] [pid 4606:tid > 140645737559808] http_request.c(440): [remote 127.0.0.1:50490] Ap-Test-Name: > test_h2_202_03b > [Wed Mar 08 22:03:35.699282 2023] [http:trace4] [pid 4606:tid > 140645737559808] http_request.c(440): [remote 127.0.0.1:50490] X: 3b > > [Wed Mar 08 22:03:35.699425 2023] [authz_core:debug] [pid 4606:tid > 140645737559808] mod_authz_core.c(818): [remote 127.0.0.1:50490] AH01626: > authorization result of Require all granted: granted > [Wed Mar 08 22:03:35.699440 2023] [authz_core:debug] [pid 4606:tid > 140645737559808] mod_authz_core.c(818): [remote 127.0.0.1:50490] AH01626: > authorization result of : granted > [Wed Mar 08 22:03:35.699446 2023] [core:trace3] [pid 4606:tid > 140645737559808] request.c(362): [remote 127.0.0.1:50490] request authorized > without authentication by access_checker_ex hook: /echohd.py > > We get the right response from the python CGI script: > > [Wed Mar 08 22:03:35.784148 2023] [cgid:trace4] [pid 4606:tid > 140645737559808] util_script.c(576): [remote 127.0.0.1:50490] Headers from > script 'echohd.py': > [Wed Mar 08 22:03:35.784206 2023] [cgid:trace4] [pid 4606:tid > 140645737559808] util_script.c(577): [remote 127.0.0.1:50490] Status: 200 > [Wed Mar 08 22:03:35.784219 2023] [cgid:trace1] [pid 4606:tid > 140645737559808] util_script.c(658): [remote 127.0.0.1:50490] Status line > from script 'echohd.py': 200 > [Wed Mar 08 22:03:35.784234 2023] [cgid:trace4] [pid 4606:tid > 140645737559808] util_script.c(577): [remote 127.0.0.1:50490] Content-Type: > text/plain > [Wed Mar 08 22:03:35.784255 2023] [filter:trace4] [pid 4606:tid > 140645737559808] mod_filter.c(169): [remote 127.0.0.1:50490] Content-Type > 'text/plain' ... > [Wed Mar 08 22:03:35.784268 2023] [filter:trace4] [pid 4606:tid > 140645737559808] mod_filter.c(181): [remote 127.0.0.1:50490] ... did not > match 'text/html' > [Wed Mar 08 22:03:35.784278 2023] [filter:trace4] [pid 4606:tid > 140645737559808] mod_filter.c(175): [remote 127.0.0.1:50490] ... matched > 'text/plain' > > deflate compression wants to kick in (no idea whether that's part of the > problem) > > [Wed Mar 08 22:03:35.784288 2023] [filter:trace2] [pid 4606:tid > 140645737559808] mod_filter.c(188): [remote 127.0.0.1:50490] Content-Type > condition for 'deflate' matched > > and now a connection reset! > > [Wed Mar 08 22:03:35.788364 2023] [cgid:trace1] [pid 4606:tid > 140645737559808] mod_cgid.c(1686): (104)Connection reset by peer: [remote > 127.0.0.1:50490] Failed to flush CGI output to client > > and another request for that URL comes in: > > [Wed Mar 08 22:03:35.788486 2023] [ssl:debug] [pid 4606:tid 140645737559808] > ssl_engine_kernel.c(422): [remote 127.0.0.1:50490] AH02034: Subsequent (No.2) > HTTPS request received for child 0 (server cgi.tests.httpd.apache.org:443) > [Wed Mar 08 22:03:35.788500 2023] [aptest:info] [pid 4606:tid > 140645737559808] [remote 127.0.0.1:50490] test[test_h2_202_03b]: POST >
Re: Current pytest failures
On 3/8/23 10:44 PM, Rainer Jung wrote: > Hi there, > > I currently get three consistent pytest failures: Do A) and B) work if you do the requests via HTTP/1.1? Regards Rüdiger
