Return-Path: X-Original-To: apmail-httpd-dev-archive@www.apache.org Delivered-To: apmail-httpd-dev-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 08AF2184CA for ; Thu, 16 Jul 2015 15:40:34 +0000 (UTC) Received: (qmail 82218 invoked by uid 500); 16 Jul 2015 15:40:10 -0000 Delivered-To: apmail-httpd-dev-archive@httpd.apache.org Received: (qmail 82163 invoked by uid 500); 16 Jul 2015 15:40:10 -0000 Mailing-List: contact dev-help@httpd.apache.org; run by ezmlm Precedence: bulk Reply-To: dev@httpd.apache.org list-help: list-unsubscribe: List-Post: List-Id: Delivered-To: mailing list dev@httpd.apache.org Received: (qmail 82153 invoked by uid 99); 16 Jul 2015 15:40:10 -0000 Received: from Unknown (HELO spamd4-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 16 Jul 2015 15:40:10 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd4-us-west.apache.org (ASF Mail Server at spamd4-us-west.apache.org) with ESMTP id 5907FC0910 for ; Thu, 16 Jul 2015 15:40:10 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd4-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: 4.881 X-Spam-Level: **** X-Spam-Status: No, score=4.881 tagged_above=-999 required=6.31 tests=[DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, HTML_MESSAGE=3, KAM_BADIPHTTP=2, RCVD_IN_MSPIKE_H3=-0.01, RCVD_IN_MSPIKE_WL=-0.01, SPF_PASS=-0.001, URIBL_BLOCKED=0.001, WEIRD_PORT=0.001] autolearn=disabled Authentication-Results: spamd4-us-west.apache.org (amavisd-new); dkim=pass (2048-bit key) header.d=gmail.com Received: from mx1-us-east.apache.org ([10.40.0.8]) by localhost (spamd4-us-west.apache.org [10.40.0.11]) (amavisd-new, port 10024) with ESMTP id XAsddifdPsEr for ; Thu, 16 Jul 2015 15:40:02 +0000 (UTC) Received: from mail-yk0-f169.google.com (mail-yk0-f169.google.com [209.85.160.169]) by mx1-us-east.apache.org (ASF Mail Server at mx1-us-east.apache.org) with ESMTPS id 976A54545A for ; Thu, 16 Jul 2015 15:40:02 +0000 (UTC) Received: by ykax123 with SMTP id x123so67277929yka.1 for ; Thu, 16 Jul 2015 08:39:11 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :content-type; bh=5eNxSqF6s4ifP++5epa8zER+i6vNygFtdJrd4KAMeCg=; b=1IA93ivBLFGbnVRFggQrjfivs8yRKN7NNhEUUtKAl4eEOaIFa1jlQaoyBu1gogE0Ug jzVd1TkpNsj7qD1doK/e0KUjwQak2syYnUWSKFzjDd03BLKQQV903+0sKCWUc9/cmm4F jO/LIiBaVbootixmfsZw7y3+cG5qdxsy1m/Pt7+i179PBGPbX9JqBAPEN6QwopGj6zKa sX7sbJqSZ0+LpC3+QpKfP8lS49bwDlmlp+eGvpoojLHavxYG6ekP5gyIIRRNHQlJBLYu Hs0ZyV64+1rd4Rx3xDXexJsee81jpPwRsnBLb+RFH+d0Y/4jcAaH9+VlRWS0d30mfeSF g5fQ== MIME-Version: 1.0 X-Received: by 10.170.187.134 with SMTP id d128mr10663940yke.103.1437061151756; Thu, 16 Jul 2015 08:39:11 -0700 (PDT) Received: by 10.13.218.7 with HTTP; Thu, 16 Jul 2015 08:39:11 -0700 (PDT) In-Reply-To: References: Date: Thu, 16 Jul 2015 17:39:11 +0200 Message-ID: Subject: Re: Congradulations on the new release(s) From: Michael Felt To: dev@httpd.apache.org Content-Type: multipart/alternative; boundary=001a1139cf227898cb051affdf81 --001a1139cf227898cb051affdf81 Content-Type: text/plain; charset=UTF-8 I really should have titled this differently - sigh! On Thu, Jul 16, 2015 at 2:20 PM, Michael Felt wrote: > I am a bit behind - yet looking forward. > > I wish to recall a pleasant get together last April in Texas just before > ApacheCon. At that time I mentioned LibreSSL and building httpd against it > (actually mod_ssl is all it amounts to). > > The build itself was quite simple - I shall repeat that now for 2.4.16 and > trunk - and send the 'patch' in. > > While build is simple - understanding the differences in test output is > daunting. > > Here I have the output of just one test t/ssl/pr12355.t - and note the > differences in the ssl_access_log - not just the error messages (I have > removed all "debug" messages from the logs as they were "in the way". > > LibreSSL is version 2.2.0, OpenSSL is version 0.9.8m (yes I know very old, > will test with latest patches later - I hope not relevant to here). > > So, please note: LibreSSL says access is: > t/logs/ssl_request_log:[16/Jul/2015:11:47:12 +0000] 127.0.0.1 - - "POST > /require-sha-cgi/perl_echo.pl HTTP/1.1" 403 237 > while OpenSSL says > t/logs/ssl_request_log:[16/Jul/2015:11:32:35 +0000] 127.0.0.1 TLSv1 > RC4-SHA "POST /require-sha-cgi/perl_echo.pl HTTP/1.1" 200 11 > > My question: what can I do to understand why OpenSSL is adding TLSv1 > RC4-SHA while LibreSSL is "- -" > > Note also in the > > ==> LibreSSL_pr12355.t.results <== > t/logs/error_log:[Thu Jul 16 11:47:12.425257 2015] [ssl:info] [pid > 389322:tid 515] [client 127.0.0.1:48676] AH01964: Connection to child 0 > established (server loopback:8532) > t/logs/error_log:[Thu Jul 16 11:47:12.613855 2015] [ssl:info] [pid > 389322:tid 515] [client 127.0.0.1:48676] AH02221: Requesting connection > re-negotiation > t/logs/error_log:[Thu Jul 16 11:47:12.614004 2015] [ssl:info] [pid > 389322:tid 515] [client 127.0.0.1:48676] AH02226: Awaiting re-negotiation > handshake > t/logs/error_log:[Thu Jul 16 11:47:12.620757 2015] [ssl:error] [pid > 389322:tid 515] [client 127.0.0.1:48676] AH02261: Re-negotiation > handshake failed: Not accepted by client!? > t/logs/error_log:[Thu Jul 16 11:47:12.620803 2015] [ssl:info] [pid > 389322:tid 515] [client 127.0.0.1:48676] AH02008: SSL library error 1 in > handshake (server loopback:8532) > t/logs/error_log:[Thu Jul 16 11:47:12.620825 2015] [ssl:info] [pid > 389322:tid 515] SSL Library Error: error:1408E0F4:SSL > routines:SSL3_GET_MESSAGE:unexpected message > t/logs/error_log:[Thu Jul 16 11:47:12.620837 2015] [ssl:info] [pid > 389322:tid 515] [client 127.0.0.1:48676] AH01998: Connection closed to > child 0 with abortive shutdown (server loopback:8532) > t/logs/error_log:[Thu Jul 16 11:47:17.073812 2015] [core:warn] [pid > 344086:tid 1] AH00045: child process 389322 still did not exit, sending a > SIGTERM > t/logs/error_log:[Thu Jul 16 11:47:19.076308 2015] [core:info] [pid > 344086:tid 1] AH00096: removed PID file > /data/prj/apache/httpd/test/t/logs/httpd.pid (pid=344086) > t/logs/error_log:[Thu Jul 16 11:47:19.076349 2015] [mpm_worker:notice] > [pid 344086:tid 1] AH00295: caught SIGTERM, shutting down > t/logs/ssl_request_log:[16/Jul/2015:11:47:10 +0000] 127.0.0.1 - - "GET > /index.html HTTP/1.1" 200 26 > t/logs/ssl_request_log:[16/Jul/2015:11:47:12 +0000] 127.0.0.1 - - "POST > /require-sha-cgi/perl_echo.pl HTTP/1.1" 403 237 > t/logs/ssl_request_log:[16/Jul/2015:11:47:12 +0000] 127.0.0.1 - - "POST > /require-md5-cgi/perl_echo.pl HTTP/1.1" 403 237 > t/logs/ssl_request_log:[16/Jul/2015:11:47:12 +0000] 127.0.0.1 - - "POST > /require-sha-cgi/perl_echo.pl HTTP/1.1" 403 237 > t/logs/ssl_request_log:[16/Jul/2015:11:47:12 +0000] 127.0.0.1 - - "POST > /require-md5-cgi/perl_echo.pl HTTP/1.1" 403 237 > > ==> OpenSSL_pr12355.t.results <== > t/logs/error_log:[Thu Jul 16 11:32:35.380665 2015] [ssl:info] [pid > 417826:tid 515] [client 127.0.0.1:39151] AH02226: Awaiting re-negotiation > handshake > t/logs/error_log:[Thu Jul 16 11:32:35.423630 2015] [ssl:info] [pid > 417826:tid 772] [client 127.0.0.1:39152] AH01964: Connection to child 1 > established (server loopback:8532) > t/logs/error_log:[Thu Jul 16 11:32:35.571262 2015] [ssl:info] [pid > 417826:tid 772] [client 127.0.0.1:39152] AH02221: Requesting connection > re-negotiation > t/logs/error_log:[Thu Jul 16 11:32:35.571354 2015] [ssl:info] [pid > 417826:tid 772] [client 127.0.0.1:39152] AH02226: Awaiting re-negotiation > handshake > t/logs/error_log:[Thu Jul 16 11:32:35.613858 2015] [ssl:info] [pid > 417826:tid 515] [client 127.0.0.1:39153] AH01964: Connection to child 0 > established (server loopback:8532) > t/logs/error_log:[Thu Jul 16 11:32:35.771440 2015] [ssl:info] [pid > 417826:tid 515] [client 127.0.0.1:39153] AH02221: Requesting connection > re-negotiation > t/logs/error_log:[Thu Jul 16 11:32:35.771533 2015] [ssl:info] [pid > 417826:tid 515] [client 127.0.0.1:39153] AH02226: Awaiting re-negotiation > handshake > t/logs/error_log:[Thu Jul 16 11:32:40.284682 2015] [core:warn] [pid > 385024:tid 1] AH00045: child process 417826 still did not exit, sending a > SIGTERM > t/logs/error_log:[Thu Jul 16 11:32:42.287551 2015] [core:info] [pid > 385024:tid 1] AH00096: removed PID file > /data/prj/apache/httpd/test/t/logs/httpd.pid (pid=385024) > t/logs/error_log:[Thu Jul 16 11:32:42.287591 2015] [mpm_worker:notice] > [pid 385024:tid 1] AH00295: caught SIGTERM, shutting down > t/logs/ssl_request_log:[16/Jul/2015:11:32:34 +0000] 127.0.0.1 - - "GET > /index.html HTTP/1.1" 200 26 > t/logs/ssl_request_log:[16/Jul/2015:11:32:35 +0000] 127.0.0.1 TLSv1 > RC4-SHA "POST /require-sha-cgi/perl_echo.pl HTTP/1.1" 200 11 > t/logs/ssl_request_log:[16/Jul/2015:11:32:35 +0000] 127.0.0.1 TLSv1 > RC4-MD5 "POST /require-md5-cgi/perl_echo.pl HTTP/1.1" 200 11 > t/logs/ssl_request_log:[16/Jul/2015:11:32:35 +0000] 127.0.0.1 TLSv1 > RC4-SHA "POST /require-sha-cgi/perl_echo.pl HTTP/1.1" 200 10000 > t/logs/ssl_request_log:[16/Jul/2015:11:32:35 +0000] 127.0.0.1 TLSv1 > RC4-MD5 "POST /require-md5-cgi/perl_echo.pl HTTP/1.1" 200 60000 > > One test in LibreSSL (first one) from test: > [Thu Jul 16 11:47:10.755088 2015] [authz_core:debug] [pid 389322:tid 515] > mod_authz_core.c(835): [client 127.0.0.1:48672] AH01628: authorization > result: granted (no directives) > [Thu Jul 16 11:47:10.755164 2015] [charset_lite:debug] [pid 389322:tid > 515] mod_charset_lite.c(219): [client 127.0.0.1:48672] AH01448: > incomplete configuration: src unspecified, dst unspe > cified > [Thu Jul 16 11:47:11.863488 2015] [ssl:info] [pid 389322:tid 772] [client > 127.0.0.1:48673] AH01964: Connection to child 1 established (server > loopback:8532) > [Thu Jul 16 11:47:11.864018 2015] [ssl:debug] [pid 389322:tid 772] > ssl_engine_kernel.c(1908): [client 127.0.0.1:48673] AH02043: SSL virtual > host for servername loopback found > [Thu Jul 16 11:47:11.982116 2015] [ssl:debug] [pid 389322:tid 772] > ssl_engine_kernel.c(1841): [client 127.0.0.1:48673] AH02041: Protocol: > TLSv1.2, Cipher: ECDHE-RSA-CHACHA20-POLY1305 (256 > /256 bits) > [Thu Jul 16 11:47:12.044850 2015] [ssl:debug] [pid 389322:tid 772] > ssl_engine_kernel.c(243): [client 127.0.0.1:48673] AH02034: Initial > (No.1) HTTPS request received for child 1 (server lo > opback:8532) > [Thu Jul 16 11:47:12.045068 2015] [ssl:debug] [pid 389322:tid 772] > ssl_engine_kernel.c(500): [client 127.0.0.1:48673] AH02220: Reconfigured > cipher suite will force renegotiation > [Thu Jul 16 11:47:12.045093 2015] [ssl:info] [pid 389322:tid 772] [client > 127.0.0.1:48673] AH02221: Requesting connection re-negotiation > [Thu Jul 16 11:47:12.045113 2015] [ssl:debug] [pid 389322:tid 772] > ssl_engine_kernel.c(791): [client 127.0.0.1:48673] AH02260: Performing > full renegotiation: complete handshake protocol ( > client does support secure renegotiation) > [Thu Jul 16 11:47:12.045174 2015] [ssl:info] [pid 389322:tid 772] [client > 127.0.0.1:48673] AH02226: Awaiting re-negotiation handshake > [Thu Jul 16 11:47:12.045340 2015] [ssl:debug] [pid 389322:tid 772] > ssl_engine_kernel.c(1908): [client 127.0.0.1:48673] AH02043: SSL virtual > host for servername loopback found > [Thu Jul 16 11:47:12.051994 2015] [ssl:error] [pid 389322:tid 772] [client > 127.0.0.1:48673] AH02261: Re-negotiation handshake failed: Not accepted > by client!? > [Thu Jul 16 11:47:12.052072 2015] [ssl:info] [pid 389322:tid 772] [client > 127.0.0.1:48673] AH02008: SSL library error 1 in handshake (server > loopback:8532) > [Thu Jul 16 11:47:12.052157 2015] [ssl:info] [pid 389322:tid 772] SSL > Library Error: error:1408E0F4:SSL routines:SSL3_GET_MESSAGE:unexpected > message > [Thu Jul 16 11:47:12.052172 2015] [ssl:info] [pid 389322:tid 772] [client > 127.0.0.1:48673] AH01998: Connection closed to child 1 with abortive > shutdown (server loopback:8532) > > First test with OpenSSL > [Thu Jul 16 12:10:47.979101 2015] [ssl:info] [pid 385024:tid 515] [client > 127.0.0.1:39154] AH01964: Connection to child 0 established (server > loopback:8532) > [Thu Jul 16 12:10:47.979609 2015] [ssl:debug] [pid 385024:tid 515] > ssl_engine_kernel.c(1936): [client 127.0.0.1:39154] AH02645: Server name > not provided via TLS extension (using default/first virtua > l host) > [Thu Jul 16 12:10:48.043295 2015] [ssl:debug] [pid 385024:tid 515] > ssl_engine_kernel.c(1841): [client 127.0.0.1:39154] AH02041: Protocol: > TLSv1, Cipher: DHE-RSA-AES256-SHA (256/256 bits) > [Thu Jul 16 12:10:48.107123 2015] [mpm_worker:error] [pid 467080:tid 1] > AH00287: server is within MinSpareThreads of MaxRequestWorkers, consider > raising the MaxRequestWorkers setting > [Thu Jul 16 12:10:48.107283 2015] [ssl:debug] [pid 385024:tid 515] > ssl_engine_kernel.c(243): [client 127.0.0.1:39154] AH02034: Initial > (No.1) HTTPS request received for child 0 (server loopback:8532 > ) > [Thu Jul 16 12:10:48.107746 2015] [ssl:debug] [pid 385024:tid 515] > ssl_engine_kernel.c(500): [client 127.0.0.1:39154] AH02220: Reconfigured > cipher suite will force renegotiation > [Thu Jul 16 12:10:48.107774 2015] [ssl:info] [pid 385024:tid 515] [client > 127.0.0.1:39154] AH02221: Requesting connection re-negotiation > [Thu Jul 16 12:10:48.107795 2015] [ssl:debug] [pid 385024:tid 515] > ssl_engine_kernel.c(791): [client 127.0.0.1:39154] AH02260: Performing > full renegotiation: complete handshake protocol (client does > support secure renegotiation) > [Thu Jul 16 12:10:48.107868 2015] [ssl:info] [pid 385024:tid 515] [client > 127.0.0.1:39154] AH02226: Awaiting re-negotiation handshake > [Thu Jul 16 12:10:48.108182 2015] [ssl:debug] [pid 385024:tid 515] > ssl_engine_kernel.c(1936): [client 127.0.0.1:39154] AH02645: Server name > not provided via TLS extension (using default/first virtua > l host) > [Thu Jul 16 12:10:48.114668 2015] [ssl:debug] [pid 385024:tid 515] > ssl_engine_kernel.c(1841): [client 127.0.0.1:39154] AH02041: Protocol: > TLSv1, Cipher: RC4-SHA (128/128 bits) > [Thu Jul 16 12:10:48.114708 2015] [authz_core:debug] [pid 385024:tid 515] > mod_authz_core.c(835): [client 127.0.0.1:39154] AH01628: authorization > result: granted (no directives) > [Thu Jul 16 12:10:48.114772 2015] [charset_lite:debug] [pid 385024:tid > 515] mod_charset_lite.c(219): [client 127.0.0.1:39154] AH01448: > incomplete configuration: src unspecified, dst unspecified > [Thu Jul 16 12:10:48.151528 2015] [ssl:debug] [pid 385024:tid 515] > ssl_engine_io.c(1003): [client 127.0.0.1:39154] AH02001: Connection > closed to child 0 with standard shutdown (server loopback:8532) > > *Observation*: I am guessing the test is failing because the > renegotiation is failing because it is downgrading to "(near) export > quality" - which many recent CVE are reporting as "very bad". > Maybe, this fail is a false "FAIL" - that 0.9.8 will always PASS because > that is what 0.9.8 does. > > *Last question*: IF you think this failure is because the renegotiation > is requesting something is bad - *then it would seem the server is > responding as it should* - and the test needs correction. Otherwise - > some help with moving forward is appreciated! > --001a1139cf227898cb051affdf81 Content-Type: text/html; charset=UTF-8 Content-Transfer-Encoding: quoted-printable
I really should have titled this differently - sigh!

On Thu, Jul 1= 6, 2015 at 2:20 PM, Michael Felt <mamfelt@gmail.com> wrote:<= br>
I am a bit behind - yet looking forward.

= I wish to recall a pleasant get together last April in Texas just before Ap= acheCon. At that time I mentioned LibreSSL and building httpd against it (a= ctually mod_ssl is all it amounts to).

The build itself was qu= ite simple - I shall repeat that now for 2.4.16 and trunk - and send the &#= 39;patch' in.

While build is simple - understanding the di= fferences in test output is daunting.

Here I have the output o= f just one test t/ssl/pr12355.t - and note the differences in the ssl_acces= s_log - not just the error messages (I have removed all "debug" m= essages from the logs as they were "in the way".

Lib= reSSL is version 2.2.0, OpenSSL is version 0.9.8m (yes I know very old, wil= l test with latest patches later - I hope not relevant to here).

So, please note: LibreSSL says access is:
t/logs/ssl_request_log:[16/= Jul/2015:11:47:12 +0000] 127.0.0.1 - - "POST /require-sha-cgi/perl_echo.pl HTTP/1.1" = 403 237
while OpenSSL says
t/logs/ssl_request_log:[16/Jul/2015:= 11:32:35 +0000] 127.0.0.1 TLSv1 RC4-SHA "POST /require-sha-cgi/perl_echo.pl HTTP/1.1" = 200 11

My question: what can I do to understand why OpenSSL is= adding TLSv1 RC4-SHA while LibreSSL is "- -"

Note a= lso in the

=3D=3D> LibreSSL_pr12355.t.r= esults <=3D=3D
t/logs/error_log:[Thu Jul 16 11:47:12.425257 2015] [ss= l:info] [pid 389322:tid 515] [client 127.0.0.1:48676] AH01964: Connection to child 0 establis= hed (server loopback:8532)
t/logs/error_log:[Thu Jul 16 11:47:12.613855 = 2015] [ssl:info] [pid 389322:tid 515] [client 127.0.0.1:48676] AH02221: Requesting connection= re-negotiation
t/logs/error_log:[Thu Jul 16 11:47:12.614004 2015] [ssl:= info] [pid 389322:tid 515] [client 127.0.0.1:48676] AH02226: Awaiting re-negotiation handshak= e
t/logs/error_log:[Thu Jul 16 11:47:12.620757 2015] [ssl:error] [pid 38= 9322:tid 515] [client = 127.0.0.1:48676] AH02261: Re-negotiation handshake failed: Not accepted= by client!?
t/logs/error_log:[Thu Jul 16 11:47:12.620803 2015] [ssl:inf= o] [pid 389322:tid 515] [client 127.0.0.1:48676] AH02008: SSL library error 1 in handshake = (server loopback:8532)
t/logs/error_log:[Thu Jul 16 11:47:12.620825 2015= ] [ssl:info] [pid 389322:tid 515] SSL Library Error: error:1408E0F4:SSL rou= tines:SSL3_GET_MESSAGE:unexpected message
t/logs/error_log:[Thu Jul 16 1= 1:47:12.620837 2015] [ssl:info] [pid 389322:tid 515] [client 127.0.0.1:48676] AH01998: Connec= tion closed to child 0 with abortive shutdown (server loopback:8532)
t/l= ogs/error_log:[Thu Jul 16 11:47:17.073812 2015] [core:warn] [pid 344086:tid= 1] AH00045: child process 389322 still did not exit, sending a SIGTERM
= t/logs/error_log:[Thu Jul 16 11:47:19.076308 2015] [core:info] [pid 344086:= tid 1] AH00096: removed PID file /data/prj/apache/httpd/test/t/logs/httpd.p= id (pid=3D344086)
t/logs/error_log:[Thu Jul 16 11:47:19.076349 2015] [mp= m_worker:notice] [pid 344086:tid 1] AH00295: caught SIGTERM, shutting down<= br>t/logs/ssl_request_log:[16/Jul/2015:11:47:10 +0000] 127.0.0.1 - - "= GET /index.html HTTP/1.1" 200 26
t/logs/ssl_request_log:[16/Jul/201= 5:11:47:12 +0000] 127.0.0.1 - - "POST /require-sha-cgi/perl_echo.pl HTTP/1.1" 403 237<= br>t/logs/ssl_request_log:[16/Jul/2015:11:47:12 +0000] 127.0.0.1 - - "= POST /require-md5-cgi/per= l_echo.pl HTTP/1.1" 403 237
t/logs/ssl_request_log:[16/Jul/2015= :11:47:12 +0000] 127.0.0.1 - - "POST /require-sha-cgi/perl_echo.pl HTTP/1.1" 403 237t/logs/ssl_request_log:[16/Jul/2015:11:47:12 +0000] 127.0.0.1 - - "P= OST /require-md5-cgi/perl= _echo.pl HTTP/1.1" 403 237

=3D=3D> OpenSSL_pr12355.t.res= ults <=3D=3D
t/logs/error_log:[Thu Jul 16 11:32:35.380665 2015] [ssl:= info] [pid 417826:tid 515] [client 127.0.0.1:39151] AH02226: Awaiting re-negotiation handshak= e
t/logs/error_log:[Thu Jul 16 11:32:35.423630 2015] [ssl:info] [pid 417= 826:tid 772] [client 1= 27.0.0.1:39152] AH01964: Connection to child 1 established (server loop= back:8532)
t/logs/error_log:[Thu Jul 16 11:32:35.571262 2015] [ssl:info]= [pid 417826:tid 772] [client 127.0.0.1:39152] AH02221: Requesting connection re-negotiation<= br>t/logs/error_log:[Thu Jul 16 11:32:35.571354 2015] [ssl:info] [pid 41782= 6:tid 772] [client 127= .0.0.1:39152] AH02226: Awaiting re-negotiation handshake
t/logs/erro= r_log:[Thu Jul 16 11:32:35.613858 2015] [ssl:info] [pid 417826:tid 515] [cl= ient 127.0.0.1:39153] AH01964: Connection to child 0 established (server loopback:8532)
t/= logs/error_log:[Thu Jul 16 11:32:35.771440 2015] [ssl:info] [pid 417826:tid= 515] [client 127.0.0.= 1:39153] AH02221: Requesting connection re-negotiation
t/logs/error_= log:[Thu Jul 16 11:32:35.771533 2015] [ssl:info] [pid 417826:tid 515] [clie= nt 127.0.0.1:39153= ] AH02226: Awaiting re-negotiation handshake
t/logs/error_log:[Thu Jul 1= 6 11:32:40.284682 2015] [core:warn] [pid 385024:tid 1] AH00045: child proce= ss 417826 still did not exit, sending a SIGTERM
t/logs/error_log:[Thu Ju= l 16 11:32:42.287551 2015] [core:info] [pid 385024:tid 1] AH00096: removed = PID file /data/prj/apache/httpd/test/t/logs/httpd.pid (pid=3D385024)
t/l= ogs/error_log:[Thu Jul 16 11:32:42.287591 2015] [mpm_worker:notice] [pid 38= 5024:tid 1] AH00295: caught SIGTERM, shutting down
t/logs/ssl_request_lo= g:[16/Jul/2015:11:32:34 +0000] 127.0.0.1 - - "GET /index.html HTTP/1.1= " 200 26
t/logs/ssl_request_log:[16/Jul/2015:11:32:35 +0000] 127.0.= 0.1 TLSv1 RC4-SHA "POST /require-sha-cgi/perl_echo.pl HTTP/1.1" 200 11
t/logs/ssl_r= equest_log:[16/Jul/2015:11:32:35 +0000] 127.0.0.1 TLSv1 RC4-MD5 "POST = /require-md5-cgi/perl_ech= o.pl HTTP/1.1" 200 11
t/logs/ssl_request_log:[16/Jul/2015:11:32= :35 +0000] 127.0.0.1 TLSv1 RC4-SHA "POST /require-sha-cgi/perl_echo.pl HTTP/1.1" 200 1= 0000
t/logs/ssl_request_log:[16/Jul/2015:11:32:35 +0000] 127.0.0.1 TLSv1= RC4-MD5 "POST /require-md5-cgi/perl_echo.pl HTTP/1.1" 200 60000

One= test in LibreSSL (first one) from test:
[Thu Jul 16 11:47:10.755088 201= 5] [authz_core:debug] [pid 389322:tid 515] mod_authz_core.c(835): [client <= a href=3D"http://127.0.0.1:48672" target=3D"_blank">127.0.0.1:48672] AH= 01628: authorization result: granted (no directives)
[Thu Jul 16 11:47:1= 0.755164 2015] [charset_lite:debug] [pid 389322:tid 515] mod_charset_lite.c= (219): [client 127.0.0= .1:48672] AH01448: incomplete configuration: src unspecified, dst unspe=
cified
[Thu Jul 16 11:47:11.863488 2015] [ssl:info] [pid 389322:tid = 772] [client 127.0.0.1= :48673] AH01964: Connection to child 1 established (server loopback:853= 2)
[Thu Jul 16 11:47:11.864018 2015] [ssl:debug] [pid 389322:tid 772] ss= l_engine_kernel.c(1908): [client 127.0.0.1:48673] AH02043: SSL virtual host for servername l= oopback found
[Thu Jul 16 11:47:11.982116 2015] [ssl:debug] [pid 389322:= tid 772] ssl_engine_kernel.c(1841): [client 127.0.0.1:48673] AH02041: Protocol: TLSv1.2, Ciph= er: ECDHE-RSA-CHACHA20-POLY1305 (256
/256 bits)
[Thu Jul 16 11:47:12.= 044850 2015] [ssl:debug] [pid 389322:tid 772] ssl_engine_kernel.c(243): [cl= ient 127.0.0.1:48673] AH02034: Initial (No.1) HTTPS request received for child 1 (server loopback:8532)
[Thu Jul 16 11:47:12.045068 2015] [ssl:debug] [pid 389322= :tid 772] ssl_engine_kernel.c(500): [client 127.0.0.1:48673] AH02220: Reconfigured cipher sui= te will force renegotiation
[Thu Jul 16 11:47:12.045093 2015] [ssl:info]= [pid 389322:tid 772] [client 127.0.0.1:48673] AH02221: Requesting connection re-negotiation<= br>[Thu Jul 16 11:47:12.045113 2015] [ssl:debug] [pid 389322:tid 772] ssl_e= ngine_kernel.c(791): [client 127.0.0.1:48673] AH02260: Performing full renegotiation: complet= e handshake protocol (
client does support secure renegotiation)
[Thu= Jul 16 11:47:12.045174 2015] [ssl:info] [pid 389322:tid 772] [client 127.0.0.1:48673] AH0222= 6: Awaiting re-negotiation handshake
[Thu Jul 16 11:47:12.045340 2015] [= ssl:debug] [pid 389322:tid 772] ssl_engine_kernel.c(1908): [client 127.0.0.1:48673] AH02043:= SSL virtual host for servername loopback found
[Thu Jul 16 11:47:12.051= 994 2015] [ssl:error] [pid 389322:tid 772] [client 127.0.0.1:48673] AH02261: Re-negotiation h= andshake failed: Not accepted by client!?
[Thu Jul 16 11:47:12.052072 20= 15] [ssl:info] [pid 389322:tid 772] [client 127.0.0.1:48673] AH02008: SSL library error 1 in = handshake (server loopback:8532)
[Thu Jul 16 11:47:12.052157 2015] [ssl:= info] [pid 389322:tid 772] SSL Library Error: error:1408E0F4:SSL routines:S= SL3_GET_MESSAGE:unexpected message
[Thu Jul 16 11:47:12.052172 2015] [ss= l:info] [pid 389322:tid 772] [client 127.0.0.1:48673] AH01998: Connection closed to child 1 w= ith abortive shutdown (server loopback:8532)

First test w= ith OpenSSL
[Thu Jul 16 12:10:47.979101 2015] [ssl:info] [pid 385024:tid= 515] [client 127.0.0.= 1:39154] AH01964: Connection to child 0 established (server loopback:85= 32)
[Thu Jul 16 12:10:47.979609 2015] [ssl:debug] [pid 385024:tid 515] s= sl_engine_kernel.c(1936): [client 127.0.0.1:39154] AH02645: Server name not provided via TLS = extension (using default/first virtua
l host)
[Thu Jul 16 12:10:48.04= 3295 2015] [ssl:debug] [pid 385024:tid 515] ssl_engine_kernel.c(1841): [cli= ent 127.0.0.1:39154] AH02041: Protocol: TLSv1, Cipher: DHE-RSA-AES256-SHA (256/256 bits)
[= Thu Jul 16 12:10:48.107123 2015] [mpm_worker:error] [pid 467080:tid 1] AH00= 287: server is within MinSpareThreads of MaxRequestWorkers, consider raisin= g the MaxRequestWorkers setting
[Thu Jul 16 12:10:48.107283 2015] [ssl:d= ebug] [pid 385024:tid 515] ssl_engine_kernel.c(243): [client 127.0.0.1:39154] AH02034: Initia= l (No.1) HTTPS request received for child 0 (server loopback:8532
)
[= Thu Jul 16 12:10:48.107746 2015] [ssl:debug] [pid 385024:tid 515] ssl_engin= e_kernel.c(500): [client 127.0.0.1:39154] AH02220: Reconfigured cipher suite will force reneg= otiation
[Thu Jul 16 12:10:48.107774 2015] [ssl:info] [pid 385024:tid 51= 5] [client 127.0.0.1:3= 9154] AH02221: Requesting connection re-negotiation
[Thu Jul 16 12:1= 0:48.107795 2015] [ssl:debug] [pid 385024:tid 515] ssl_engine_kernel.c(791)= : [client 127.0.0.1:39= 154] AH02260: Performing full renegotiation: complete handshake protoco= l (client does
=C2=A0support secure renegotiation)
[Thu Jul 16 12:10:= 48.107868 2015] [ssl:info] [pid 385024:tid 515] [client 127.0.0.1:39154] AH02226: Awaiting re= -negotiation handshake
[Thu Jul 16 12:10:48.108182 2015] [ssl:debug] [pi= d 385024:tid 515] ssl_engine_kernel.c(1936): [client 127.0.0.1:39154] AH02645: Server name no= t provided via TLS extension (using default/first virtua
l host)
[Thu= Jul 16 12:10:48.114668 2015] [ssl:debug] [pid 385024:tid 515] ssl_engine_k= ernel.c(1841): [client 127.0.0.1:39154] AH02041: Protocol: TLSv1, Cipher: RC4-SHA (128/128 bi= ts)
[Thu Jul 16 12:10:48.114708 2015] [authz_core:debug] [pid 385024:tid= 515] mod_authz_core.c(835): [client 127.0.0.1:39154] AH01628: authorization result: granted = (no directives)
[Thu Jul 16 12:10:48.114772 2015] [charset_lite:debug] [= pid 385024:tid 515] mod_charset_lite.c(219): [client 127.0.0.1:39154] AH01448: incomplete con= figuration: src unspecified, dst unspecified
[Thu Jul 16 12:10:48.151528= 2015] [ssl:debug] [pid 385024:tid 515] ssl_engine_io.c(1003): [client 127.0.0.1:39154] AH020= 01: Connection closed to child 0 with standard shutdown (server loopback:85= 32)

Observation: I am guessing the test is failing= because the renegotiation is failing because it is downgrading to "(n= ear) export quality" - which many recent CVE are reporting as "ve= ry bad".
Maybe, this fail is a false "FAIL" - = that 0.9.8 will always PASS because that is what 0.9.8 does.

<= div>Last question: IF you think this failure is because the renegoti= ation is requesting something is bad - then it would seem the server is = responding as it should - and the test needs correction. Otherwise - so= me help with moving forward is appreciated!

--001a1139cf227898cb051affdf81--