[Mod_nss-list] nss_engine_io error message

[Rob Crittenden]

Erica Johansson wrote:
> I'm having an issue with one of our production servers that utilizes
> mod_nss.  Httpd shortly after a restart will be ultimately max out the
> cpu.  This is a rather robust machine (quad core, 2G RAM, but the memory
> is barely touched) with not much traffic passing through ultimately.
> Max would be ~200-250 in an hour, excluding the health checks from the
> load balancer. This does not serve out content, but acts purely as a
> proxy/reverse proxy.  There is really nothing in the logs of note
> unfortunately.  The only thing I've found in the logs that raises any
> question at all in my mind is this in the error_log:
>
> [Mon Apr 25 06:08:50 2011] [debug] nss_engine_io.c(656): SSL connection
> destroyed without being closed
>
> Here is the complete attempt:
> [Mon Apr 25 06:08:50 2011] [debug] proxy_util.c(1488): [client
> 10.71.47.129] proxy: https: found worker
> https://server01.domain.com/D2EP/ for
> https://server01.domain.com/D2EP/msg_data/submit
> [Mon Apr 25 06:08:50 2011] [debug] mod_proxy.c(966): Running scheme
> https handler (attempt 0)
> [Mon Apr 25 06:08:50 2011] [debug] mod_proxy_http.c(1976): proxy: HTTP:
> serving URL https://server01.domain.com/D2EP/msg_data/submit
> [Mon Apr 25 06:08:50 2011] [debug] proxy_util.c(2044): proxy: HTTPS: has
> acquired connection for (server01.domain.com <http://server01.domain.com>)
> [Mon Apr 25 06:08:50 2011] [debug] proxy_util.c(2102): proxy: connecting
> https://server01.domain.com/D2EP/msg_data/submit to server01.g
> ovtrip.com:443 <http://ovtrip.com:443>
> [Mon Apr 25 06:08:50 2011] [debug] proxy_util.c(2195): proxy: connected
> /D2EP/msg_data/submit to server01.domain.com:443
> <http://server01.domain.com:443>
> [Mon Apr 25 06:08:50 2011] [debug] nss_engine_io.c(656): SSL connection
> destroyed without being closed
> [Mon Apr 25 06:08:50 2011] [debug] proxy_util.c(2286): proxy: HTTPS:
> backend socket is disconnected.
>
> We have many of those throughout the day...with all of them after the
> same attempted connection. (I would estimate that 90% of that connection
> attempt results in the proceeding error message, today looks like 206
> were triggered thus far)
>
> My question ultimately is how that could potentially impact the httpd
> server?  (Sorry, asking here since it's mod_nss that is complaining
> about it)
>
> Something is clearly triggering something within the server, and I want
> to make sure I'm not missing something related to mod_nss.
>
> Thank you for your time!
> Erica

What version of Apache are you running?

mod_nss pushes an I/O filter into Apache. This I/O filter handles 
converting data to/from SSL. When this message appears the filter is 
being cleaned up without having been shut down properly. The shutdown 
function locks reading and writing so closing will not block. So 
potentially this could cause mod_nss to block if a connection is closed 
with pending I/O.

I assume you aren't seeing this on every proxy request? Is this 
reproducable by you? e.g. can you generate a request to generate this 
message? I'd be curious if the request is successful from mod_proxy's 
perspective.

thanks

rob