Hi Chris,
Am 16.05.2022 um 19:48 schrieb Christopher Schultz:
I've been looking into this a little more in my production environment.
These errors are not super common, but there seems to be a steady
trickle of errors from my two services that have human users. I see 0
errors for my API-based services, which makes me think that I don't have
any performance issues... I probably have human users disappearing for
random reasons.
Could be unstable (mobile) client connections. Or people already
clicking on the next frontend action before they received the complete
response. But that is speculating. So it is right, you try to identify
some individual reasons to understand more.
The errors in mod_jk.log look like this:
[Sun May 15 04:19:15.643 2022] [5859:139625025315392] [info]
ajp_process_callback::jk_ajp_common.c (2077): (myworker) Writing to
client aborted or client network problems
[Sun May 15 04:19:15.644 2022] [5859:139625025315392] [info]
ajp_service::jk_ajp_common.c (2773): (myworker) sending request to
tomcat failed (unrecoverable), because of client write error (attempt=1)
[Sun May 15 04:19:15.646 2022] [5859:139625025315392] [info]
service::jk_lb_worker.c (1595): service failed, worker myworker is in
local error state
[Sun May 15 04:19:15.646 2022] [5859:139625025315392] [info]
service::jk_lb_worker.c (1614): unrecoverable error 200, request failed.
Client failed in the middle of request, we can't recover to another
instance.
[Sun May 15 04:19:15.646 2022] [5859:139625025315392] [info]
jk_handler::mod_jk.c (2984): Aborting connection for worker=myworker
(Note that the last message "Aborting connection for worker=myworker"
may have a bug; my actual worker name has a name containing a hyphen (-)
and only the text before the hyphen is being emitted in that error
message.)
Strange, never observed that, but maybe never used a hyphen. Docs say,
hypens are allowed. Would be interesting to do a server startup with
trace-Logging and see where things corresponding to the name start to go
wrong. But of course not related to sporadic client failures.
Anyway, when researching these errors, it would be helpful to me to know
which requests are failing. By looking at the access_log, I only see a
single request logged for 04:19:15 on that server so it's probably the
right one, but httpd says that the response code is 302 instead of e.g.
50x for an error.
What I typically do:
- log "%P:%{tid}P" in your Apache httpd custom LogFormat used for the
access log.
- make sure, I log in in the Apache httpd access log the request
timestamp including milli or microseconds (not default but
configurable). Can be done by using the %{format}t syntax in the
LogFormat and adding "usec_frac" to the format.
- adding %D to the access log format (duration in microseconds)
- remember that Apache logs start of request as default time stamp, but
mod_jk logs at the moment of error, so later than start of request.
Finding the right access log line for a mod_jk error log line now means:
- filter the access log according to the PID:TID logged in the mod_jk
error log. In your case 5859:139625025315392. We know, that the requests
handled by one thread in one process are run strictly sequentially.
- look for the last request in this filtered list, that by access log
line timestamp started before (or unlikely exactly at) the point in time
given by the mod_jk access log. If you find one exactly add, it might be
also the one directly before.
- look at the request durations of these one or two requests to double
check, whether the times fit.
If you can spare the additional log line bytes, you can additionally log
the end of request timestamp in the apache access log (prefix "format"
by "begin:").
When we log these kinds of errors, it would be great to know a few
things IMO:
1. What was the URL of the request
2. How long did the client wait for the response before we found we
couldn't write to the stream (or, conversely, the start-timestamp of the
request as well as the timestamp of the error, which I think is already
in the log itself)
I see the place in the code where the error is generated, but I'm not
familiar enough with the code to know how to add that kind of thing. The
function in question (ajp_process_callback) has a pointer to a
jk_ws_service_t structure. Is it as simple as also logging like this?
/* convert start-time to a string */
char[32] timestamp;
apr_strftime(timestamp, NULL, 32, "%Y-%m-%d %H:%M:%S",
r->r->request_time);
/* emit a detailed log message */
jk_log(l, JK_LOG_INFO,
"(%s) Request to (%s %s) started at %s,%ld",
ae->worker->name, r->method, r->req_uri, timestamp,
r->r->request_time.tm_usec);
Does anyone think this might be generally useful?
I'll have a look at your other mail on this next.
Best regards,
Rainer
Thanks,
-chris
On 3/25/22 08:37, Christopher Schultz wrote:
Rainer,
On 3/24/22 05:50, Rainer Jung wrote:
Hi Chris,
client errors in jk log are always errors occurring when mod_jk tries
to write back what it got from the backend using web server APIs to
the client of the web server (user, browser etc.). So they point to a
problem between and including the web server and something in front
of it.
Especially during performance problems, client errors are expected as
a consequence, because whenever people try to reload, the browser
closes the original connection and sending back response data via
this connection later fails.
I was pretty sure this was the case. Is that specifically documented
anywhere? If not, I'd like to clarify that in the documentation for
mod_jk.
Thanks,
-chris
Am 23.03.2022 um 13:08 schrieb Christopher Schultz:
All,
What kinds of things will cause a "client error" in mod_jk's
accounting? Does that mean things like unexpected disconnects on the
part of the remote client (i.e. web browser), or does it mean
failure of the jk module itself to connect (as a client) to the
back-end Tomcat?
I'm starting to see situations where we have small numbers of client
errors occurring "all the time", meaning that we accumulate maybe
10-20 per day. If that's web browser disconnects then I don't care
at all. If it's a problem I have with my internal networking and
resource-allocation, then it's something I have to adjust.
Thanks,
-chris
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
