httpd-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Mathihalli, Madhusudan" <mad...@hp.com>
Subject RE: mod_ssl not sending Alert upon close ?
Date Thu, 05 Feb 2004 22:03:29 GMT
Okay. here's what I think is happening : (Client => C Server -> S)

C  -> S : initiates connection
C <-> S : handshake
S  -> C : server sends application data
S  -> C : server tries to read from the socket
          -> finds nothing (0 bytes returned)
          -> assumes transaction is completed, and starts cleanup process
          -> closes the connection first
          -> frees the pool, which invokes ssl_io_filter_cleanup() and inturn ssl_io_filter_shutdown()
          -> ssl_io_filter_shutdown() tries to send 'Close notify'
             OOPS ! The connection has already been terminated 

Any comments ?

-Madhu

>-----Original Message-----
>From: Mathihalli, Madhusudan 
>Sent: Thursday, February 05, 2004 1:31 PM
>To: dev@httpd.apache.org
>Subject: RE: mod_ssl not sending Alert upon close ?
>
>
>I tried using all the three 'unclean', 'standard' and 
>'accurate' shutdown methods. I'm using MSIE 6.0 (and can 
>attach the ssldump comparision for both Apache 1.3 and 2.x if required)
>
>As regards reproducing, I think you can reproduce it in any 
>standard installation. Here's a partial 'tusc' output. As you 
>can see, the socket has been closed much before the Alert 
>message was *tried* to be sent !
>
>-Madhu
>
>1076016143.543190 {621927} write(10, 0x7af0fcc8, 81) ..... = 81
>    [ T h u   F e b   0 5   1 3 : 2 2 : 2 3   2 0 0 4 ]   [ i n f o 
>    ]   b i o _ f i l t e r _ o u t _ f l u s h :   t r y i n g   t 
>    o   f l u s h   b l e n :   6 7 \n
>1076016143.543457 {621927} writev(13, 0x7af0fc88, 1) ..... = 67
>    1403\0\001011603\0\08 86e5adcaP q 5 b2bdd810ffc11adc- e aaa613cc
>    \0H 9fe6d61 l D ! # cas M w W 80x b4\r` t cdce\n6 cd, P L f5x 4 
>    d0O e 
>1076016143.543774 {621927} fcntl(12, F_SETLKW, 0x7b019574) = 0
>1076016143.543943 {621927} time(NULL) .................... = 1076016143
>1076016143.544052 {621927} fcntl(12, F_SETLKW, 0x7b019584) = 0
>1076016143.920487 {621927} poll(0x7af0fe50, 1, 300000) ... = 1
>1076016143.920587 {621927} read(13, 0x402b6810, 8000) .... = 0
>1076016143.920685 {621927} gettimeofday(0x7af0f448, NULL)  = 0
>1076016143.920813 {621927} shutdown(13, SHUT_WR) ......... = 0
>1076016143.920898 {621927} poll(0x7af0f650, 1, 2000) ..... = 1
>1076016143.920984 {621927} read(13, 0x7af0f208, 512) ..... = 0
>1076016143.924105 {621927} close(13) ..................... = 0
>1076016143.924239 {621927} gettimeofday(0x7af11788, NULL)  = 0
>1076016143.932207 {621927} write(10, 0x7af0f708, 98) ..... = 98
>    [ T h u   F e b   0 5   1 3 : 2 2 : 2 3   2 0 0 4 ]   [ i n f o 
>    ]   b i o _ f i l t e r _ o u t _ w r i t e :   t r y i n g   t 
>    o   w r i t e   i n l :   2 3   ( l e n g t h   0   b l e n   0 
>    ) \n
>1076016143.932510 {621927} gettimeofday(0x7af11788, NULL)  = 0
>1076016143.932608 {621927} write(10, 0x7af0f708, 86) ..... = 86
>    [ T h u   F e b   0 5   1 3 : 2 2 : 2 3   2 0 0 4 ]   [ i n f o 
>    ]   b i o _ f i l t e r _ o u t _ w r i t e :   b u f f e r i n 
>    g   d a t a   ( N O   W R I T E   Y E T ) \n
>1076016143.932844 {621927} gettimeofday(0x7af11448, NULL)  = 0
>1076016143.932934 {621927} write(10, 0x7af0f3c8, 135) .... = 135
>    [ T h u   F e b   0 5   1 3 : 2 2 : 2 3   2 0 0 4 ]   [ i n f o 
>    ]   C o n n e c t i o n   t o   c h i l d   1   c l o s e d   w 
>    i t h   s t a n d a r d   s h u t d o w n ( s e r v e r   l u g 
>    i a . c u p . h p . c o m : 4 4 3 ,   c l i e n t   1 5 . 0 . 7 
>    0 . 1 8 8 ) \n
>
>>-----Original Message-----
>>From: Joe Orton [mailto:jorton@redhat.com]
>>Sent: Thursday, February 05, 2004 12:10 PM
>>To: dev@httpd.apache.org
>>Subject: Re: mod_ssl not sending Alert upon close ?
>>
>>
>>I've seen some unclean shutdown errors a few times but never 
>managed to
>>get a repro case.  What client are you using, how do you 
>>reproduce this?  
>>I presume you have the same SetEnvIf ssl-unclean-shutdown settings for
>>broken clients when comparing 1.3 and 2.0 behaviour?
>>
>>On Thu, Feb 05, 2004 at 11:06:57AM -0800, Mathihalli, 
>Madhusudan wrote:
>>> Hi,
>>> 	It's been a while since I played with the Apache code, 
>>and it'll 
>>> be nice if somebody can help me here.
>>> 
>>> I put some debug statements in the ssl_engine_io.c - in 
>>> bio_filter_out_write() and bio_filter_in_read() to see if the alert 
>>> message is actually being sent, and got the following output:
>>> 
>>> bio_filter_out_write: trying to write inl: 900 (length 0 blen 0)
>>> bio_filter_out_write: buffering data (NO WRITE YET)
>>> bio_filter_out_flush: trying to flush blen: 900
>>> bio_filter_out_write: trying to write inl: 67 (length 0 blen 0)
>>> bio_filter_out_write: buffering data (NO WRITE YET)
>>> bio_filter_out_flush: trying to flush blen: 67
>>> (70014)End of file found: bio_filter_in_read: got EOF - 
>>returning -1 (at the end)
>>> (70014)End of file found: SSL input filter read failed.
>>> ------>> Does the socket fd get closed at this point ?
>>> bio_filter_out_write: trying to write inl: 23 (length 0 blen 0)
>>> bio_filter_out_write: buffering data (NO WRITE YET)
>>> ------>> This is the close notify message that 
>>SSL_set_shutdown() was trying to send - but it never gets sent 
>>because the message is buffered. Maybe we need to revisit the 
>>logic of bio_filter_out_write() ?
>>
>>And you're sure that the client sent a close notify alert before the
>>EOF?
>>
>>joe
>>
>

Mime
View raw message