You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@serf.apache.org by Branko Čibej <br...@apache.org> on 2018/05/05 15:12:42 UTC

Re: Test failure on trunk on macOS

On 29.04.2018 11:24, Branko Čibej wrote:
> On 25.04.2018 00:08, Branko Čibej wrote:
>> On 20.04.2018 12:55, Branko Čibej wrote:
>>> Hi!
>>>
>>> Has anyone seen this failure before, on latest macOS with latest tools
>>> and homebrewed APR and OpenSSL:
>>>
>>> There was 1 failure:
>>> 1) test_ssl_missing_client_certificate: /Users/brane/src/asf/serf/serf-trunk/test/test_ssl.c:1869: expected <120172> but was <120199>
>>>
>>>
>>> (This is with running "scons check" in an out-of-tree build.)
>>>
>>> The test case expects the status SERF_ERROR_SSL_SETUP_FAILED but
>>> receives SERF_ERROR_ISSUE_IN_TESTSUITE.
>>>
>>> It's strange that the same issue doesn't show up on the OSX buildbot —
>>> but that has a different version of the OS, APR, APU and OpenSSL.
>> This is what I found so far:
>>
>>   * the call to 'cctx->handshake()' in _mhRunServerLoop returns APR_EGENERAL
>>       o the handshake function called is sslHandshake() in MockHTTP_server.c
>>   * the problem is sensitive to timing; if I set MH_VERBOSE to 1, all
>>     tests pass ... even if I redirect stderr to a file or to /dev/null.
>>     This is true even if I just selectively enable the error logging in
>>     sslHandshake().
>>       o if I do that, I get the following log:
>>
>>         2018-04-25T00:05:33.097912+02 [cp:56236 sp:30118] SSL Error 1: Library=20, Function=128, Reason=255
>>
>>         140735571477376:error:140800FF:SSL routines:ssl3_accept:unknown state:s3_srvr.c:869:
> Well this is interesting ... this test failure does not manifest if I
> build with OpenSSL 1.1.x, only 1.0.2. There's either something wrong
> with my (or rather, Homebrew's) build of OpenSSL 1.0.x, or the "recent"
> 1.1.x compatibility changes somehow broke 1.0.x support.

I updated my OSX build slave from OpenSSL 1.0.2k to 1.0.2o today, and
the same failures started showing up there, too. So it has to be either
a bug in the latest version of OpenSSL 1.0.x, or in the way we use it.

-- Brane


Re: Test failure on trunk on macOS

Posted by Branko Čibej <br...@apache.org>.
On 05.05.2018 21:21, Branko Čibej wrote:
> On 05.05.2018 19:19, Lieven Govaerts wrote:
>> On 5 May 2018 at 18:03, Branko Čibej <br...@apache.org> wrote:
>>
>>> On 05.05.2018 17:12, Branko Čibej wrote:
>>>> On 29.04.2018 11:24, Branko Čibej wrote:
>>>>> On 25.04.2018 00:08, Branko Čibej wrote:
>>>>>> On 20.04.2018 12:55, Branko Čibej wrote:
>>>>>>> Hi!
>>>>>>>
>>>>>>> Has anyone seen this failure before, on latest macOS with latest tools
>>>>>>> and homebrewed APR and OpenSSL:
>>>>>>>
>>>>>>> There was 1 failure:
>>>>>>> 1) test_ssl_missing_client_certificate: /Users/brane/src/asf/serf/
>>> serf-trunk/test/test_ssl.c:1869: expected <120172> but was <120199>
>>>>>>> (This is with running "scons check" in an out-of-tree build.)
>>>>>>>
>>>>>>> The test case expects the status SERF_ERROR_SSL_SETUP_FAILED but
>>>>>>> receives SERF_ERROR_ISSUE_IN_TESTSUITE.
>>>>>>>
>>>>>>> It's strange that the same issue doesn't show up on the OSX buildbot —
>>>>>>> but that has a different version of the OS, APR, APU and OpenSSL.
>>>>>> This is what I found so far:
>>>>>>
>>>>>>   * the call to 'cctx->handshake()' in _mhRunServerLoop returns
>>> APR_EGENERAL
>>>>>>       o the handshake function called is sslHandshake() in
>>> MockHTTP_server.c
>>>>>>   * the problem is sensitive to timing; if I set MH_VERBOSE to 1, all
>>>>>>     tests pass ... even if I redirect stderr to a file or to /dev/null.
>>>>>>     This is true even if I just selectively enable the error logging in
>>>>>>     sslHandshake().
>>>>>>       o if I do that, I get the following log:
>>>>>>
>>>>>>         2018-04-25T00:05:33.097912+02 [cp:56236 sp:30118] SSL Error 1:
>>> Library=20, Function=128, Reason=255
>>>>>>         140735571477376:error:140800FF:SSL
>>> routines:ssl3_accept:unknown state:s3_srvr.c:869:
>>>>> Well this is interesting ... this test failure does not manifest if I
>>>>> build with OpenSSL 1.1.x, only 1.0.2. There's either something wrong
>>>>> with my (or rather, Homebrew's) build of OpenSSL 1.0.x, or the "recent"
>>>>> 1.1.x compatibility changes somehow broke 1.0.x support.
>>>> I updated my OSX build slave from OpenSSL 1.0.2k to 1.0.2o today, and
>>>> the same failures started showing up there, too. So it has to be either
>>>> a bug in the latest version of OpenSSL 1.0.x, or in the way we use it.
>>> This test failure happens with OpenSSL 1.0.2n and 1.0.2o, but not with
>>> 1.0.2m and earlier. Looking at the OpenSSL changelog[1], this is a
>>> likely candidate:
>>>
>>>>  Changes between 1.0.2m and 1.0.2n [7 Dec 2017]
>>>>
>>>>   *) Read/write after SSL object in error state
>>> If that's the case, then it's most likely due to a bug in Serf. The fact
>>> that enabling logging in the tests (i.e., reading the error state) makes
>>> the test failure go away seems to point in this direction, too.
>>> Unfortunately I'm not familiar enough with those parts of Serf, and it
>>> would be really nice if someone else could try to track this down. It
>>> looks suspiciously like we're ignoring a return code somewhere ...
>>>
>>>
>> ​Given that the error is ​"SERF_ERROR_ISSUE_IN_TESTSUITE", doesn't it make
>> more sense that any read/write misbehaviour originates in the test
>> framework, and not in the serf library?
>
> Could likely be something in the MockHTTP server. If I add this single
> line in the sslHandshake() function there, all tests pass:
>
> Index: test/MockHTTPinC/MockHTTP_server.c
> ===================================================================
> --- test/MockHTTPinC/MockHTTP_server.c	(revision 1830991)
> +++ test/MockHTTPinC/MockHTTP_server.c	(working copy)
> @@ -3008,6 +3008,8 @@ static apr_status_t sslHandshake(_mhClientCtx_t *c
>      sslCtx_t *ssl_ctx = cctx->ssl_ctx;
>      int result;
>  
> +    ERR_print_errors_fp(stderr);
> +
>      if (ssl_ctx->renegotiate) {
>          if (!SSL_do_handshake(ssl_ctx->ssl))
>              return APR_EGENERAL;


Even the following change is enough to make all tests pass:

Index: test/MockHTTPinC/MockHTTP_server.c
===================================================================
--- test/MockHTTPinC/MockHTTP_server.c	(revision 1830991)
+++ test/MockHTTPinC/MockHTTP_server.c	(working copy)
@@ -3040,6 +3040,8 @@ static apr_status_t sslHandshake(_mhClientCtx_t *c
                     int func = ERR_GET_FUNC(l);
                     int reason = ERR_GET_REASON(l);
 
+                    printf("foo\n");
+
                     if (lib == ERR_LIB_SSL
                         && (reason == SSL_R_PEER_DID_NOT_RETURN_A_CERTIFICATE
                             || reason == ERR_R_INTERNAL_ERROR)) {



-- Brane


Re: Test failure on trunk on macOS

Posted by Branko Čibej <br...@apache.org>.
On 05.05.2018 19:19, Lieven Govaerts wrote:
> On 5 May 2018 at 18:03, Branko Čibej <br...@apache.org> wrote:
>
>> On 05.05.2018 17:12, Branko Čibej wrote:
>>> On 29.04.2018 11:24, Branko Čibej wrote:
>>>> On 25.04.2018 00:08, Branko Čibej wrote:
>>>>> On 20.04.2018 12:55, Branko Čibej wrote:
>>>>>> Hi!
>>>>>>
>>>>>> Has anyone seen this failure before, on latest macOS with latest tools
>>>>>> and homebrewed APR and OpenSSL:
>>>>>>
>>>>>> There was 1 failure:
>>>>>> 1) test_ssl_missing_client_certificate: /Users/brane/src/asf/serf/
>> serf-trunk/test/test_ssl.c:1869: expected <120172> but was <120199>
>>>>>>
>>>>>> (This is with running "scons check" in an out-of-tree build.)
>>>>>>
>>>>>> The test case expects the status SERF_ERROR_SSL_SETUP_FAILED but
>>>>>> receives SERF_ERROR_ISSUE_IN_TESTSUITE.
>>>>>>
>>>>>> It's strange that the same issue doesn't show up on the OSX buildbot —
>>>>>> but that has a different version of the OS, APR, APU and OpenSSL.
>>>>> This is what I found so far:
>>>>>
>>>>>   * the call to 'cctx->handshake()' in _mhRunServerLoop returns
>> APR_EGENERAL
>>>>>       o the handshake function called is sslHandshake() in
>> MockHTTP_server.c
>>>>>   * the problem is sensitive to timing; if I set MH_VERBOSE to 1, all
>>>>>     tests pass ... even if I redirect stderr to a file or to /dev/null.
>>>>>     This is true even if I just selectively enable the error logging in
>>>>>     sslHandshake().
>>>>>       o if I do that, I get the following log:
>>>>>
>>>>>         2018-04-25T00:05:33.097912+02 [cp:56236 sp:30118] SSL Error 1:
>> Library=20, Function=128, Reason=255
>>>>>         140735571477376:error:140800FF:SSL
>> routines:ssl3_accept:unknown state:s3_srvr.c:869:
>>>> Well this is interesting ... this test failure does not manifest if I
>>>> build with OpenSSL 1.1.x, only 1.0.2. There's either something wrong
>>>> with my (or rather, Homebrew's) build of OpenSSL 1.0.x, or the "recent"
>>>> 1.1.x compatibility changes somehow broke 1.0.x support.
>>> I updated my OSX build slave from OpenSSL 1.0.2k to 1.0.2o today, and
>>> the same failures started showing up there, too. So it has to be either
>>> a bug in the latest version of OpenSSL 1.0.x, or in the way we use it.
>> This test failure happens with OpenSSL 1.0.2n and 1.0.2o, but not with
>> 1.0.2m and earlier. Looking at the OpenSSL changelog[1], this is a
>> likely candidate:
>>
>>>  Changes between 1.0.2m and 1.0.2n [7 Dec 2017]
>>>
>>>   *) Read/write after SSL object in error state
>> If that's the case, then it's most likely due to a bug in Serf. The fact
>> that enabling logging in the tests (i.e., reading the error state) makes
>> the test failure go away seems to point in this direction, too.
>> Unfortunately I'm not familiar enough with those parts of Serf, and it
>> would be really nice if someone else could try to track this down. It
>> looks suspiciously like we're ignoring a return code somewhere ...
>>
>>
> ​Given that the error is ​"SERF_ERROR_ISSUE_IN_TESTSUITE", doesn't it make
> more sense that any read/write misbehaviour originates in the test
> framework, and not in the serf library?


Could likely be something in the MockHTTP server. If I add this single
line in the sslHandshake() function there, all tests pass:

Index: test/MockHTTPinC/MockHTTP_server.c
===================================================================
--- test/MockHTTPinC/MockHTTP_server.c	(revision 1830991)
+++ test/MockHTTPinC/MockHTTP_server.c	(working copy)
@@ -3008,6 +3008,8 @@ static apr_status_t sslHandshake(_mhClientCtx_t *c
     sslCtx_t *ssl_ctx = cctx->ssl_ctx;
     int result;
 
+    ERR_print_errors_fp(stderr);
+
     if (ssl_ctx->renegotiate) {
         if (!SSL_do_handshake(ssl_ctx->ssl))
             return APR_EGENERAL;




-- Brane


Re: Test failure on trunk on macOS

Posted by Branko Čibej <br...@apache.org>.
On 05.05.2018 19:19, Lieven Govaerts wrote:
> On 5 May 2018 at 18:03, Branko Čibej <br...@apache.org> wrote:
>
>> On 05.05.2018 17:12, Branko Čibej wrote:
>>> On 29.04.2018 11:24, Branko Čibej wrote:
>>>> On 25.04.2018 00:08, Branko Čibej wrote:
>>>>> On 20.04.2018 12:55, Branko Čibej wrote:
>>>>>> Hi!
>>>>>>
>>>>>> Has anyone seen this failure before, on latest macOS with latest tools
>>>>>> and homebrewed APR and OpenSSL:
>>>>>>
>>>>>> There was 1 failure:
>>>>>> 1) test_ssl_missing_client_certificate: /Users/brane/src/asf/serf/
>> serf-trunk/test/test_ssl.c:1869: expected <120172> but was <120199>
>>>>>>
>>>>>> (This is with running "scons check" in an out-of-tree build.)
>>>>>>
>>>>>> The test case expects the status SERF_ERROR_SSL_SETUP_FAILED but
>>>>>> receives SERF_ERROR_ISSUE_IN_TESTSUITE.
>>>>>>
>>>>>> It's strange that the same issue doesn't show up on the OSX buildbot —
>>>>>> but that has a different version of the OS, APR, APU and OpenSSL.
>>>>> This is what I found so far:
>>>>>
>>>>>   * the call to 'cctx->handshake()' in _mhRunServerLoop returns
>> APR_EGENERAL
>>>>>       o the handshake function called is sslHandshake() in
>> MockHTTP_server.c
>>>>>   * the problem is sensitive to timing; if I set MH_VERBOSE to 1, all
>>>>>     tests pass ... even if I redirect stderr to a file or to /dev/null.
>>>>>     This is true even if I just selectively enable the error logging in
>>>>>     sslHandshake().
>>>>>       o if I do that, I get the following log:
>>>>>
>>>>>         2018-04-25T00:05:33.097912+02 [cp:56236 sp:30118] SSL Error 1:
>> Library=20, Function=128, Reason=255
>>>>>         140735571477376:error:140800FF:SSL
>> routines:ssl3_accept:unknown state:s3_srvr.c:869:
>>>> Well this is interesting ... this test failure does not manifest if I
>>>> build with OpenSSL 1.1.x, only 1.0.2. There's either something wrong
>>>> with my (or rather, Homebrew's) build of OpenSSL 1.0.x, or the "recent"
>>>> 1.1.x compatibility changes somehow broke 1.0.x support.
>>> I updated my OSX build slave from OpenSSL 1.0.2k to 1.0.2o today, and
>>> the same failures started showing up there, too. So it has to be either
>>> a bug in the latest version of OpenSSL 1.0.x, or in the way we use it.
>> This test failure happens with OpenSSL 1.0.2n and 1.0.2o, but not with
>> 1.0.2m and earlier. Looking at the OpenSSL changelog[1], this is a
>> likely candidate:
>>
>>>  Changes between 1.0.2m and 1.0.2n [7 Dec 2017]
>>>
>>>   *) Read/write after SSL object in error state
>> If that's the case, then it's most likely due to a bug in Serf. The fact
>> that enabling logging in the tests (i.e., reading the error state) makes
>> the test failure go away seems to point in this direction, too.
>> Unfortunately I'm not familiar enough with those parts of Serf, and it
>> would be really nice if someone else could try to track this down. It
>> looks suspiciously like we're ignoring a return code somewhere ...
>>
>>
> ​Given that the error is ​"SERF_ERROR_ISSUE_IN_TESTSUITE", doesn't it make
> more sense that any read/write misbehaviour originates in the test
> framework, and not in the serf library?

Possibly. "Serf" includes "tests" and "CuTest" and "MockHTTP", since we
have a copy of everything in our repository.

-- Brane


Re: Test failure on trunk on macOS

Posted by Lieven Govaerts <lg...@mobsol.be>.
On 5 May 2018 at 18:03, Branko Čibej <br...@apache.org> wrote:

> On 05.05.2018 17:12, Branko Čibej wrote:
> > On 29.04.2018 11:24, Branko Čibej wrote:
> >> On 25.04.2018 00:08, Branko Čibej wrote:
> >>> On 20.04.2018 12:55, Branko Čibej wrote:
> >>>> Hi!
> >>>>
> >>>> Has anyone seen this failure before, on latest macOS with latest tools
> >>>> and homebrewed APR and OpenSSL:
> >>>>
> >>>> There was 1 failure:
> >>>> 1) test_ssl_missing_client_certificate: /Users/brane/src/asf/serf/
> serf-trunk/test/test_ssl.c:1869: expected <120172> but was <120199>
> >>>>
> >>>>
> >>>> (This is with running "scons check" in an out-of-tree build.)
> >>>>
> >>>> The test case expects the status SERF_ERROR_SSL_SETUP_FAILED but
> >>>> receives SERF_ERROR_ISSUE_IN_TESTSUITE.
> >>>>
> >>>> It's strange that the same issue doesn't show up on the OSX buildbot —
> >>>> but that has a different version of the OS, APR, APU and OpenSSL.
> >>> This is what I found so far:
> >>>
> >>>   * the call to 'cctx->handshake()' in _mhRunServerLoop returns
> APR_EGENERAL
> >>>       o the handshake function called is sslHandshake() in
> MockHTTP_server.c
> >>>   * the problem is sensitive to timing; if I set MH_VERBOSE to 1, all
> >>>     tests pass ... even if I redirect stderr to a file or to /dev/null.
> >>>     This is true even if I just selectively enable the error logging in
> >>>     sslHandshake().
> >>>       o if I do that, I get the following log:
> >>>
> >>>         2018-04-25T00:05:33.097912+02 [cp:56236 sp:30118] SSL Error 1:
> Library=20, Function=128, Reason=255
> >>>
> >>>         140735571477376:error:140800FF:SSL
> routines:ssl3_accept:unknown state:s3_srvr.c:869:
> >> Well this is interesting ... this test failure does not manifest if I
> >> build with OpenSSL 1.1.x, only 1.0.2. There's either something wrong
> >> with my (or rather, Homebrew's) build of OpenSSL 1.0.x, or the "recent"
> >> 1.1.x compatibility changes somehow broke 1.0.x support.
> > I updated my OSX build slave from OpenSSL 1.0.2k to 1.0.2o today, and
> > the same failures started showing up there, too. So it has to be either
> > a bug in the latest version of OpenSSL 1.0.x, or in the way we use it.
>
> This test failure happens with OpenSSL 1.0.2n and 1.0.2o, but not with
> 1.0.2m and earlier. Looking at the OpenSSL changelog[1], this is a
> likely candidate:
>
> >  Changes between 1.0.2m and 1.0.2n [7 Dec 2017]
> >
> >   *) Read/write after SSL object in error state
>
> If that's the case, then it's most likely due to a bug in Serf. The fact
> that enabling logging in the tests (i.e., reading the error state) makes
> the test failure go away seems to point in this direction, too.
> Unfortunately I'm not familiar enough with those parts of Serf, and it
> would be really nice if someone else could try to track this down. It
> looks suspiciously like we're ignoring a return code somewhere ...
>
>
​Given that the error is ​"SERF_ERROR_ISSUE_IN_TESTSUITE", doesn't it make
more sense that any read/write misbehaviour originates in the test
framework, and not in the serf library?

Lieven



> -- Brane
>
> [1] https://www.openssl.org/news/cl102.txt
>
>

Re: Test failure on trunk on macOS

Posted by Branko Čibej <br...@apache.org>.
On 05.05.2018 17:12, Branko Čibej wrote:
> On 29.04.2018 11:24, Branko Čibej wrote:
>> On 25.04.2018 00:08, Branko Čibej wrote:
>>> On 20.04.2018 12:55, Branko Čibej wrote:
>>>> Hi!
>>>>
>>>> Has anyone seen this failure before, on latest macOS with latest tools
>>>> and homebrewed APR and OpenSSL:
>>>>
>>>> There was 1 failure:
>>>> 1) test_ssl_missing_client_certificate: /Users/brane/src/asf/serf/serf-trunk/test/test_ssl.c:1869: expected <120172> but was <120199>
>>>>
>>>>
>>>> (This is with running "scons check" in an out-of-tree build.)
>>>>
>>>> The test case expects the status SERF_ERROR_SSL_SETUP_FAILED but
>>>> receives SERF_ERROR_ISSUE_IN_TESTSUITE.
>>>>
>>>> It's strange that the same issue doesn't show up on the OSX buildbot —
>>>> but that has a different version of the OS, APR, APU and OpenSSL.
>>> This is what I found so far:
>>>
>>>   * the call to 'cctx->handshake()' in _mhRunServerLoop returns APR_EGENERAL
>>>       o the handshake function called is sslHandshake() in MockHTTP_server.c
>>>   * the problem is sensitive to timing; if I set MH_VERBOSE to 1, all
>>>     tests pass ... even if I redirect stderr to a file or to /dev/null.
>>>     This is true even if I just selectively enable the error logging in
>>>     sslHandshake().
>>>       o if I do that, I get the following log:
>>>
>>>         2018-04-25T00:05:33.097912+02 [cp:56236 sp:30118] SSL Error 1: Library=20, Function=128, Reason=255
>>>
>>>         140735571477376:error:140800FF:SSL routines:ssl3_accept:unknown state:s3_srvr.c:869:
>> Well this is interesting ... this test failure does not manifest if I
>> build with OpenSSL 1.1.x, only 1.0.2. There's either something wrong
>> with my (or rather, Homebrew's) build of OpenSSL 1.0.x, or the "recent"
>> 1.1.x compatibility changes somehow broke 1.0.x support.
> I updated my OSX build slave from OpenSSL 1.0.2k to 1.0.2o today, and
> the same failures started showing up there, too. So it has to be either
> a bug in the latest version of OpenSSL 1.0.x, or in the way we use it.

This test failure happens with OpenSSL 1.0.2n and 1.0.2o, but not with
1.0.2m and earlier. Looking at the OpenSSL changelog[1], this is a
likely candidate:

>  Changes between 1.0.2m and 1.0.2n [7 Dec 2017]
>
>   *) Read/write after SSL object in error state

If that's the case, then it's most likely due to a bug in Serf. The fact
that enabling logging in the tests (i.e., reading the error state) makes
the test failure go away seems to point in this direction, too.
Unfortunately I'm not familiar enough with those parts of Serf, and it
would be really nice if someone else could try to track this down. It
looks suspiciously like we're ignoring a return code somewhere ...

-- Brane

[1] https://www.openssl.org/news/cl102.txt