Re: Re: Non Blocking write in apache

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 

Hi,

in the apache error_log with trace6, it is trying to flush because it reached thresold_max_buffer. But at the same time, it is adding data in buffer which increases it size to to more than 52KB and fails on NonStop. How should I stop apache so that it should go to select function till 52KB success. 

Attaching error_log with new change.

Thanks
Hemant 

On Mon, Sep 17, 2018 at 4:01 PM Hemant Chaudhary <hemantdude.chaudhary@xxxxxxxxx> wrote:
Hi Yann,

Thanks for your explanation. I got  the issue.
Actually NonStop has maximum limit of 52KB only for writev. Therefore I was getting 4022 after 49KB. Because after 49KB, apache is adding 8K more bytes which leads to 56KB. Therefore, writev was failing.

To solve this, I have changed  THRESHOLD_MAX_BUFFER in core_filter.c to 50000. But again I am seeing that after 49KB, apache is adding 8192 Bytes in it, which leads to failure of writev again.

Do I need to change in more places or the above fix should work.
Thanks
Hemant

On Sun, Sep 16, 2018 at 4:48 PM Yann Ylavic <ylavic.dev@xxxxxxxxx> wrote:
Hi Hermant,

On Fri, Sep 14, 2018 at 1:53 PM Hemant Chaudhary
<hemantdude.chaudhary@xxxxxxxxx> wrote:
>
> Please don't get confuse with Cygwin(Windows). I am running apache on NonStop(Tandem).

Well, isn't the error_log attached to the previous message relevant
(be it cygwin or not)?
Btw, LogLevel trace6 would help here.

> I have put breakpoint at apr_poll() but it is not going there.
>
> Few Events of writing :
> 1) apache writes 779 bytes to tomcat from apr_socket_sendv() function and writev functions returns success.
> 2) apache writes 24604 bytes to tomcat from apr_socket_sendv() function but writev function returns -1 with EWOULDBLOCK and it has timeout=0(because set in writev_nonblocking())
> 3) apache again tries to write 32796 to tomcat from apr_socket_sendv() function but writev function returns -1 with EWOULDBLOCK and it has timeout=0(because set in writev_nonblocking()).
> 4) apache again tries to write 40988 to tomcat from apr_socket_sendv() function but writev function returns -1 with EWOULDBLOCK and it has timeout=0(because set in writev_nonblocking()).
> 5) apache again tries to write 49180 to tomcat from apr_socket_sendv() function but writev function returns -1 with EWOULDBLOCK and it has timeout=0(because set in writev_nonblocking()).

OK, all those EWOULDBLOCK make the core output filter to bufferize the
"pending" data for the next time it's called.

> 6) After this I am getting 4022 error.

Here the 64K bufferized limit/threshold is reached
(non_file_bytes_in_brigade >= THRESHOLD_MAX_BUFFER in
ap_core_output_filter()), so the core output filter can't continue
nonblocking anymore and enters send_brigade_blocking(), which does
send_brigade_nonblocking() + apr_poll() until the 64K buffer is sent
completely.

However it seems that on your system the first call to
send_brigade_nonblocking() fails (since apr_poll() is never called),
possibly a limit on apr_socket_sendv() (i.e. writev() syscall), either
more than 64K total bytes or nvec > 4?

I think you need to debug/gdb in send_brigade_nonblocking() for this
last call and determine where and why send_brigade_nonblocking() =>
writev_nonblocking() => apr_socket_send() => writev(vec, nvec) fails.
Maybe a unit test (a simple standalone main() program) can determine
the limits for writev() on your system, so that the right values for
THRESHOLD_MAX_BUFFER and MAX_IOVEC_TO_WRITE (in
"server/core_filters.c") can be tuned for NonStop(Tandem) ...

Hope that helps,
Yann.

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@xxxxxxxxxxxxxxxx
For additional commands, e-mail: users-help@xxxxxxxxxxxxxxxx

[Mon Sep 17 11:41:16.226341 2018] [core:trace5] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\server\protocol.c(645): [client 15.213.82.149:54687] Request received from client: POST /FileUploadServletExample/uploadFile HTTP/1.1
[Mon Sep 17 11:41:16.226712 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_request.c(420): [client 15.213.82.149:54687] Headers received from client:, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.226806 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_request.c(424): [client 15.213.82.149:54687]   Host: 15.213.91.33:5010, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.226820 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_request.c(424): [client 15.213.82.149:54687]   Connection: keep-alive, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.226829 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_request.c(424): [client 15.213.82.149:54687]   Content-Length: 1846656, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.226838 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_request.c(424): [client 15.213.82.149:54687]   Cache-Control: max-age=0, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.226847 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_request.c(424): [client 15.213.82.149:54687]   Origin: http://15.213.91.33:5010, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.226855 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_request.c(424): [client 15.213.82.149:54687]   Upgrade-Insecure-Requests: 1, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.226864 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_request.c(424): [client 15.213.82.149:54687]   Content-Type: multipart/form-data; boundary=----WebKitFormBoundary9Y7XjD2wrDhGPtCA, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.226874 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_request.c(424): [client 15.213.82.149:54687]   User-Agent: Mozilla/5.0 (Windows NT 6.1; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.79 Safari/537.36, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.226885 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_request.c(424): [client 15.213.82.149:54687]   Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.226902 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_request.c(424): [client 15.213.82.149:54687]   Referer: http://15.213.91.33:5010/FileUploadServletExample/, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.226911 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_request.c(424): [client 15.213.82.149:54687]   Accept-Encoding: gzip, deflate, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.226920 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_request.c(424): [client 15.213.82.149:54687]   Accept-Language: en-US,en;q=0.9, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.226929 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_request.c(424): [client 15.213.82.149:54687]   Cookie: JSESSIONID=5E4A4705453B786B7F7C129FE1E0B420, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.226958 2018] [proxy:trace2] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\proxy\mod_proxy.c(663): [client 15.213.82.149:54687] AH03461: attempting to match URI path '/FileUploadServletExample/uploadFile' against prefix '/' for proxying, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.226971 2018] [proxy:trace1] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\proxy\mod_proxy.c(748): [client 15.213.82.149:54687] AH03464: URI path '/FileUploadServletExample/uploadFile' matches proxy handler 'proxy:http://15.213.91.33:8199/FileUploadServletExample/uploadFile', referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.227001 2018] [authz_core:debug] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\aaa\mod_authz_core.c(809): [client 15.213.82.149:54687] AH01626: authorization result of Require all granted: granted, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.227012 2018] [authz_core:debug] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\aaa\mod_authz_core.c(809): [client 15.213.82.149:54687] AH01626: authorization result of <RequireAny>: granted, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.227022 2018] [core:trace3] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\server\request.c(304): [client 15.213.82.149:54687] request authorized without authentication by access_checker_ex hook: /FileUploadServletExample/uploadFile, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.227039 2018] [proxy_http:trace1] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\proxy\mod_proxy_http.c(60): [client 15.213.82.149:54687] HTTP: canonicalising URL //15.213.91.33:8199/FileUploadServletExample/uploadFile, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.227069 2018] [proxy:trace2] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\proxy\proxy_util.c(1962): [client 15.213.82.149:54687] http: found worker http://15.213.91.33:8199/ for http://15.213.91.33:8199/FileUploadServletExample/uploadFile, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.227083 2018] [proxy:debug] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\proxy\mod_proxy.c(1228): [client 15.213.82.149:54687] AH01143: Running scheme http handler (attempt 0), referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.227095 2018] [proxy_http:trace1] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\proxy\mod_proxy_http.c(1904): [client 15.213.82.149:54687] HTTP: serving URL http://15.213.91.33:8199/FileUploadServletExample/uploadFile, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.227107 2018] [proxy:debug] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\proxy\proxy_util.c(2156): AH00942: HTTP: has acquired connection for (15.213.91.33)
[Mon Sep 17 11:41:16.227118 2018] [proxy:debug] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\proxy\proxy_util.c(2209): [client 15.213.82.149:54687] AH00944: connecting http://15.213.91.33:8199/FileUploadServletExample/uploadFile to 15.213.91.33:8199, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.227136 2018] [proxy:debug] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\proxy\proxy_util.c(2418): [client 15.213.82.149:54687] AH00947: connected /FileUploadServletExample/uploadFile to 15.213.91.33:8199, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:16.227383 2018] [proxy:trace2] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\proxy\proxy_util.c(2853): HTTP: fam 2 socket created to connect to 15.213.91.33
[Mon Sep 17 11:41:16.229691 2018] [proxy:debug] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\proxy\proxy_util.c(2887): AH02824: HTTP: connection established with 15.213.91.33:8199 (15.213.91.33)
[Mon Sep 17 11:41:16.229717 2018] [proxy:debug] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\proxy\proxy_util.c(3054): AH00962: HTTP: connection complete to 15.213.91.33:8199 (15.213.91.33)
[Mon Sep 17 11:41:26.335389 2018] [core:trace6] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\server\core_filters.c(525): [remote 15.213.91.33:8199] core_output_filter: flushing because of THRESHOLD_MAX_BUFFER
[Mon Sep 17 11:41:26.937967 2018] [core:trace1] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\server\core_filters.c(547): (4022)Invalid function argument: [remote 15.213.91.33:8199] core_output_filter: writing data to the network
[Mon Sep 17 11:41:26.938014 2018] [proxy:error] [pid 1107296306:tid 577217628620783620] (4022)Invalid function argument: [client 15.213.82.149:54687] AH01084: pass request body failed to 15.213.91.33:8199 (15.213.91.33), referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:26.938037 2018] [proxy_http:error] [pid 1107296306:tid 577217628620783620] [client 15.213.82.149:54687] AH01097: pass request body failed to 15.213.91.33:8199 (15.213.91.33) from 15.213.82.149 (), referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:26.938048 2018] [proxy:debug] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\proxy\proxy_util.c(2171): AH00943: HTTP: has released connection for (15.213.91.33)
[Mon Sep 17 11:41:27.015407 2018] [http:trace3] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_filters.c(1128): [client 15.213.82.149:54687] Response sent with status 502, headers:, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:27.015427 2018] [http:trace5] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_filters.c(1135): [client 15.213.82.149:54687]   Date: Mon, 17 Sep 2018 11:41:16 GMT, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:27.015437 2018] [http:trace5] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_filters.c(1138): [client 15.213.82.149:54687]   Server: Apache/2.4.29 (Unix) OpenSSL/1.0.2d, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:27.015449 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_filters.c(957): [client 15.213.82.149:54687]   Content-Length: 232, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:27.015458 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_filters.c(957): [client 15.213.82.149:54687]   Keep-Alive: timeout=5, max=100, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:27.015467 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_filters.c(957): [client 15.213.82.149:54687]   Connection: Keep-Alive, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:27.015475 2018] [http:trace4] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\modules\http\http_filters.c(957): [client 15.213.82.149:54687]   Content-Type: text/html; charset=iso-8859-1, referer: http://15.213.91.33:5010/FileUploadServletExample/
[Mon Sep 17 11:41:27.015501 2018] [core:trace6] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\server\core_filters.c(525): [client 15.213.82.149:54687] core_output_filter: flushing because of FLUSH bucket
[Mon Sep 17 11:41:33.268613 2018] [core:trace6] [pid 1107296306:tid 577217628620783620] C:\cygwin64\home\apache29\apache-2.4.29\httpd-2.4.29\server\core_filters.c(525): [client 15.213.82.149:54687] core_output_filter: flushing because of FLUSH bucket

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@xxxxxxxxxxxxxxxx
For additional commands, e-mail: users-help@xxxxxxxxxxxxxxxx
[Index of Archives]     [Open SSH Users]     [Linux ACPI]     [Linux Kernel]     [Linux Laptop]     [Kernel Newbies]     [Security]     [Netfilter]     [Bugtraq]     [Squid]     [Yosemite News]     [MIPS Linux]     [ARM Linux]     [Linux Security]     [Linux RAID]     [Samba]     [Video 4 Linux]     [Device Mapper]

  Powered by Linux