Hmmm, ok, I really don't think Elving's hypothesis is correct as I just attempted to simulate what he described:
1) Click on a link that takes at least 15-20 seconds to return.
2) Click on the "Stop" button after 10 seconds of waiting.
3) Click on the same link again to simulate user impatiently re-clicking on the link.
Also tried re-clicking on the link without clicking Stop.
In all these cases, the HTTP 500 on the web server did not occur. Sometimes the request would appear in the app server's log signifying that the the app server managed to return the response before I clicked on Stop but most of the time not.
Ok, looks like Elving is probably right. Earlier this afternoon (in the +0800 timezone), I had been trying out the role of an impatient user using Firefox over the cor. I did not manage to simulate the HTTP 500 responses.
Just now though, I managed to get a colleague to do the same using IE with a home ADSL account. And waddaya know, he managed to simulate the errors. It's not consistent though. Even if his action sequences were roughly equal, over 20 iterations, we only manage to simulate the error 5 times.
So I take back my words, Elving, sorry :)
But is this supposed to be how the logs reflect this behavior? It doesn't seem entirely logical to me. I can understand a Bad Gateway response, but an Internal Server Error?
You can add %duration% to the log format if you're interested in how long it took to process the request. %duration% records the processing time in microseconds.
(Note that a difference of 1 second between log entry timestamps does not necessarily indicate that precisely 1 second elapsed between the two events. The difference between the two could be as little as a single clock tick or as large as 1.999... seconds.)