test failures in downloaded Green CI image
In the process of tying to review the slices for a few issues, I downloaded build #30500 Pharo3.0-win.zip from [1]. (Normally I use files.pharo.org but I wanted to ensure it was a "GREEN" build.) However before loading the slice to review I double-checked the baseline test results by running all tests from TestRunner. I had presumed all tests would be green but was surprised by some failures in the result. Well it maybe it has something to do with environment, but it would be nice for it to be clean to help isoalte any errors introduced by the slice under review. Before I log anything on Fogbugz in case someone can advise anything obvious, the Test Runner result is shown below [2]. My platform is 64-bit Windows 7 Home Premium Service Pack 1. I'll try to follow up with more specific info on each line. cheers -ben [1] https://ci.inria.fr/pharo/job/Pharo-3.0-Update-Step-4-Publish/566/ [2] 11426 run, 11386 passes, 12 skipped, 26 expected failures, 12 failures, 2 errors, 0 unexpected passes FAILURES MetacelloRepositorySqueakCommonTestCase >> #testAsRepositorySpecFor MetacelloRepositorySqueakCommonTestCase >> #testDirectoryRepository MetacelloRepositorySqueakCommonTestCase >> #testFileTreeRepository RPackageReadOnlyCompleteSetupTest >> #testAddTag RPackageReadOnlyCompleteSetupTest >> #testAddTagNames KMDispatcherTestCase >> #testAttach RPackageSetTest >> #testPolymorphicWithPackageInfo BehaviorTest >> #testBehaviorRespectsPolymorphismWithTraitBehavior BehaviorTest >> #testLocalMethodsOfTheClassShouldNotBeRepeatedInItsTraits ProcessTest >> #testHighPriorityOverridesWaitTime ReleaseTest >> #testLocalMethodsOfTheClassShouldNotBeRepeatedInItsTraits ReleaseTest >> #testUndeclared ERRORS MetacelloTutorialTestCase >> #testProjectRef14 ZnServerTests >> #testRequestLineTooLong
btc@openinworld.com wrote:
In the process of tying to review the slices for a few issues, I downloaded build #30500 Pharo3.0-win.zip from [1]. (Normally I use files.pharo.org but I wanted to ensure it was a "GREEN" build.) However before loading the slice to review I double-checked the baseline test results by running all tests from TestRunner. I had presumed all tests would be green but was surprised by some failures in the result. Well it maybe it has something to do with environment, but it would be nice for it to be clean to help isoalte any errors introduced by the slice under review. Before I log anything on Fogbugz in case someone can advise anything obvious, the Test Runner result is shown below [2].
My platform is 64-bit Windows 7 Home Premium Service Pack 1. I'll try to follow up with more specific info on each line.
cheers -ben
[1] https://ci.inria.fr/pharo/job/Pharo-3.0-Update-Step-4-Publish/566/
[2] FAILURE ZnServerTests >> #testRequestLineTooLong I extracted #testRequestLineTooLong to something I can evaluate from Workspace...
| numX url fudge | fudge := 0. numX := ZnConstants maximumLineLength - fudge . (url := ZnUrl fromString: 'http://localhost:1704/') addPathSegment: #echo; addPathSegment: (String new: numX withAll: $X). ZnClient new beOneShot; logToTranscript; url: url; get; response That fails with initial fudge factor of 0 - with 'ZnUnknownHttpVerion.' Here is the Transcript (including logging from ZnServer)... 2013-10-20 00:45:40 489094 D Executing request/response loop 2013-10-20 00:45:40 505527 I Wrote a ZnRequest(GET /echo/XXXXXXXX...XXXXX) 2013-10-20 00:45:40 505527 D Sent headers Accept: */* User-Agent: Zinc HTTP Components 1.0 Connection: close Host: localhost:1704 2013-10-20 00:45:40 489094 D ZnLineTooLong bad request while parsing 2013-10-20 00:45:40 489094 I Wrote a ZnResponse(400 Bad Request text/plain;charset=utf-8 27B) 2013-10-20 00:45:40 489094 D Closing streamZnStatusLine With a fudge factor of 9 it still fails, but with 10 it succeeds. Interestingly, inspect 'url' shows... http://localhost:1704/echo/XXXXXXXXXXXXXXXXXXXXXXXXXX...etc ...and 10 characters = 1704/echo/ but then correlation does not equal cause. How should we proceed? cheers -ben
Ben, The goal of the test is to confirm that the server returns an error (refuses a request) when any line, in this case the first so called request line, it too long. Hence the artificially constructed URL. Of course, if you make it shorter, at one point it will be short enough so that it no longer fails - but that defeats the purpose of the test ;-) Now, the problem with this test and 3 other ones that are related, checking the reaction to other limits, is that they pass on Mac and Linux, but fail (randomly) on Windows, when ZdcSocketStream is used instead of SocketStream, currently the default. I have already looked into this, but up to now I failed to find the problem. The Socket class uses a number of primitives which have totally different implementations on the 3 platforms. Yes, I could use some help, but this is not easy. I also think there already is an issue for this, but I can't find it. Sven On 19 Oct 2013, at 18:54, btc@openinworld.com wrote:
btc@openinworld.com wrote:
In the process of tying to review the slices for a few issues, I downloaded build #30500 Pharo3.0-win.zip from [1]. (Normally I use files.pharo.org but I wanted to ensure it was a "GREEN" build.) However before loading the slice to review I double-checked the baseline test results by running all tests from TestRunner. I had presumed all tests would be green but was surprised by some failures in the result. Well it maybe it has something to do with environment, but it would be nice for it to be clean to help isoalte any errors introduced by the slice under review. Before I log anything on Fogbugz in case someone can advise anything obvious, the Test Runner result is shown below [2].
My platform is 64-bit Windows 7 Home Premium Service Pack 1. I'll try to follow up with more specific info on each line.
cheers -ben
[1] https://ci.inria.fr/pharo/job/Pharo-3.0-Update-Step-4-Publish/566/
[2] FAILURE ZnServerTests >> #testRequestLineTooLong I extracted #testRequestLineTooLong to something I can evaluate from Workspace...
| numX url fudge | fudge := 0. numX := ZnConstants maximumLineLength - fudge . (url := ZnUrl fromString: 'http://localhost:1704/') addPathSegment: #echo; addPathSegment: (String new: numX withAll: $X). ZnClient new beOneShot; logToTranscript; url: url; get; response
That fails with initial fudge factor of 0 - with 'ZnUnknownHttpVerion.' Here is the Transcript (including logging from ZnServer)... 2013-10-20 00:45:40 489094 D Executing request/response loop 2013-10-20 00:45:40 505527 I Wrote a ZnRequest(GET /echo/XXXXXXXX...XXXXX) 2013-10-20 00:45:40 505527 D Sent headers Accept: */* User-Agent: Zinc HTTP Components 1.0 Connection: close Host: localhost:1704
2013-10-20 00:45:40 489094 D ZnLineTooLong bad request while parsing 2013-10-20 00:45:40 489094 I Wrote a ZnResponse(400 Bad Request text/plain;charset=utf-8 27B) 2013-10-20 00:45:40 489094 D Closing streamZnStatusLine
With a fudge factor of 9 it still fails, but with 10 it succeeds. Interestingly, inspect 'url' shows... http://localhost:1704/echo/XXXXXXXXXXXXXXXXXXXXXXXXXX...etc ...and 10 characters = 1704/echo/ but then correlation does not equal cause.
How should we proceed?
cheers -ben
Sven, I've spent the day poking around in different parts of ZnServers and Sockets and got about as far as I can. I've reported a lot of stuff on the Case [1], and some expert review would now be useful - but you might want to skip to the end where I suggest a way that the problem might be invoked/simulated at your end on an otherwise working Max or Linux system. cheers -ben btc@openinworld.com wrote:
While trying to debug this I found the error went away when I put a breakpoint to step through ZnMultiThreadedServer>>executeOneRequestResponseOn: Presuming a race condition I played with adding delays until I managed to isolate the following case...
ZnMultiThreadedServer>>executeOneRequestResponseOn: stream | request response | (Delay forMilliseconds: 30) wait. "<----- <20 fails. >30 succeeds." (request := self readRequestSafely: stream) ifNil: [ ^ true ] ifNotNil: [ response := self handleRequest: request. self augmentResponse: response forRequest: request. self writeResponseSafely: response on: stream. response useConnection: stream. ]. ^ request wantsConnectionClose or: [ response wantsConnectionClose ]
I've got more info coming, so I've raised ticket [1] to continue discussion.
cheers -ben
[1] https://pharo.fogbugz.com/default.asp?11960
Sven Van Caekenberghe wrote:
Ben,
The goal of the test is to confirm that the server returns an error (refuses a request) when any line, in this case the first so called request line, it too long. Hence the artificially constructed URL. Of course, if you make it shorter, at one point it will be short enough so that it no longer fails - but that defeats the purpose of the test ;-)
Now, the problem with this test and 3 other ones that are related, checking the reaction to other limits, is that they pass on Mac and Linux, but fail (randomly) on Windows, when ZdcSocketStream is used instead of SocketStream, currently the default. I have already looked into this, but up to now I failed to find the problem. The Socket class uses a number of primitives which have totally different implementations on the 3 platforms.
Yes, I could use some help, but this is not easy.
I also think there already is an issue for this, but I can't find it.
Sven
On 19 Oct 2013, at 18:54, btc@openinworld.com wrote:
btc@openinworld.com wrote:
In the process of tying to review the slices for a few issues, I downloaded build #30500 Pharo3.0-win.zip from [1]. (Normally I use files.pharo.org but I wanted to ensure it was a "GREEN" build.) However before loading the slice to review I double-checked the baseline test results by running all tests from TestRunner. I had presumed all tests would be green but was surprised by some failures in the result. Well it maybe it has something to do with environment, but it would be nice for it to be clean to help isoalte any errors introduced by the slice under review. Before I log anything on Fogbugz in case someone can advise anything obvious, the Test Runner result is shown below [2].
My platform is 64-bit Windows 7 Home Premium Service Pack 1. I'll try to follow up with more specific info on each line.
cheers -ben
[1] https://ci.inria.fr/pharo/job/Pharo-3.0-Update-Step-4-Publish/566/
[2] FAILURE ZnServerTests >> #testRequestLineTooLong
I extracted #testRequestLineTooLong to something I can evaluate from Workspace...
| numX url fudge | fudge := 0. numX := ZnConstants maximumLineLength - fudge . (url := ZnUrl fromString: 'http://localhost:1704/') addPathSegment: #echo; addPathSegment: (String new: numX withAll: $X). ZnClient new beOneShot; logToTranscript; url: url; get; response
That fails with initial fudge factor of 0 - with 'ZnUnknownHttpVerion.' Here is the Transcript (including logging from ZnServer)... 2013-10-20 00:45:40 489094 D Executing request/response loop 2013-10-20 00:45:40 505527 I Wrote a ZnRequest(GET /echo/XXXXXXXX...XXXXX) 2013-10-20 00:45:40 505527 D Sent headers Accept: */* User-Agent: Zinc HTTP Components 1.0 Connection: close Host: localhost:1704
2013-10-20 00:45:40 489094 D ZnLineTooLong bad request while parsing 2013-10-20 00:45:40 489094 I Wrote a ZnResponse(400 Bad Request text/plain;charset=utf-8 27B) 2013-10-20 00:45:40 489094 D Closing streamZnStatusLine
With a fudge factor of 9 it still fails, but with 10 it succeeds. Interestingly, inspect 'url' shows... http://localhost:1704/echo/XXXXXXXXXXXXXXXXXXXXXXXXXX...etc ...and 10 characters = 1704/echo/ but then correlation does not equal cause.
How should we proceed?
cheers -ben
Ben, Thanks for spending time looking into this. Now, you produced an enormous amount of information, but I am still confused. I have to come back to you when I have more time to rerun my older unfinished experiments using Windows 8.1 in VirtualBox, so that I can reformulate how I see things. Hopefully I will be able to understand what you were up to ;-) Sven On 20 Oct 2013, at 18:38, btc@openinworld.com wrote:
Sven,
I've spent the day poking around in different parts of ZnServers and Sockets and got about as far as I can. I've reported a lot of stuff on the Case [1], and some expert review would now be useful - but you might want to skip to the end where I suggest a way that the problem might be invoked/simulated at your end on an otherwise working Max or Linux system.
cheers -ben
btc@openinworld.com wrote:
While trying to debug this I found the error went away when I put a breakpoint to step through ZnMultiThreadedServer>>executeOneRequestResponseOn: Presuming a race condition I played with adding delays until I managed to isolate the following case...
ZnMultiThreadedServer>>executeOneRequestResponseOn: stream | request response | (Delay forMilliseconds: 30) wait. "<----- <20 fails. >30 succeeds." (request := self readRequestSafely: stream) ifNil: [ ^ true ] ifNotNil: [ response := self handleRequest: request. self augmentResponse: response forRequest: request. self writeResponseSafely: response on: stream. response useConnection: stream. ]. ^ request wantsConnectionClose or: [ response wantsConnectionClose ]
I've got more info coming, so I've raised ticket [1] to continue discussion.
cheers -ben
[1] https://pharo.fogbugz.com/default.asp?11960
Sven Van Caekenberghe wrote:
Ben,
The goal of the test is to confirm that the server returns an error (refuses a request) when any line, in this case the first so called request line, it too long. Hence the artificially constructed URL. Of course, if you make it shorter, at one point it will be short enough so that it no longer fails - but that defeats the purpose of the test ;-)
Now, the problem with this test and 3 other ones that are related, checking the reaction to other limits, is that they pass on Mac and Linux, but fail (randomly) on Windows, when ZdcSocketStream is used instead of SocketStream, currently the default. I have already looked into this, but up to now I failed to find the problem. The Socket class uses a number of primitives which have totally different implementations on the 3 platforms.
Yes, I could use some help, but this is not easy.
I also think there already is an issue for this, but I can't find it.
Sven
On 19 Oct 2013, at 18:54, btc@openinworld.com wrote:
btc@openinworld.com wrote: >>> In the process of tying to review the slices for a few issues, I downloaded build #30500 Pharo3.0-win.zip from [1]. (Normally I use files.pharo.org but I wanted to ensure it was a "GREEN" build.) However before loading the slice to review I double-checked the baseline test results by running all tests from TestRunner. I had presumed all tests would be green but was surprised by some failures in the result. Well it maybe it has something to do with environment, but it would be nice for it to be clean to help isoalte any errors introduced by the slice under review. Before I log anything on Fogbugz in case someone can advise anything obvious, the Test Runner result is shown below [2].
My platform is 64-bit Windows 7 Home Premium Service Pack 1. I'll try to follow up with more specific info on each line.
cheers -ben
[1] https://ci.inria.fr/pharo/job/Pharo-3.0-Update-Step-4-Publish/566/
[2] FAILURE ZnServerTests >> #testRequestLineTooLong >> I extracted #testRequestLineTooLong to something I can evaluate from Workspace...
| numX url fudge | fudge := 0. numX := ZnConstants maximumLineLength - fudge . (url := ZnUrl fromString: 'http://localhost:1704/') addPathSegment: #echo; addPathSegment: (String new: numX withAll: $X). ZnClient new beOneShot; logToTranscript; url: url; get; response
That fails with initial fudge factor of 0 - with 'ZnUnknownHttpVerion.' Here is the Transcript (including logging from ZnServer)... 2013-10-20 00:45:40 489094 D Executing request/response loop 2013-10-20 00:45:40 505527 I Wrote a ZnRequest(GET /echo/XXXXXXXX...XXXXX) 2013-10-20 00:45:40 505527 D Sent headers Accept: */* User-Agent: Zinc HTTP Components 1.0 Connection: close Host: localhost:1704
2013-10-20 00:45:40 489094 D ZnLineTooLong bad request while parsing 2013-10-20 00:45:40 489094 I Wrote a ZnResponse(400 Bad Request text/plain;charset=utf-8 27B) 2013-10-20 00:45:40 489094 D Closing streamZnStatusLine
With a fudge factor of 9 it still fails, but with 10 it succeeds. Interestingly, inspect 'url' shows... http://localhost:1704/echo/XXXXXXXXXXXXXXXXXXXXXXXXXX...etc ...and 10 characters = 1704/echo/ but then correlation does not equal cause.
How should we proceed?
cheers -ben
>
I updated https://pharo.fogbugz.com/f/cases/10908/Three-tests-failing-on-Windows-ZnSer... On 21 Oct 2013, at 00:58, btc@openinworld.com wrote:
As a detailed symptom of the problem, there seems consistent behaviour with the following Transcript logging
Now adding some Transcript logging into: * ZnResponse>>writeOn: Transcript crShow: ' ' , statusLine printString. * ZnMessage>>writeOn: Transcript crShow: ' ' , self headers printString. * ZnMultiThreadedServer>>writeResponseBad:on: Transcript crShow: ' ' , response printString.
...that SUCCESSFUL requests log CLIENT headers before the SERVER headers.
(CLIENT) ZnHeaders('Accept'->'*/*' 'Connection'->'close' 'Host'->'localhost:1700' 'User-Agent'->'Zinc HTTP Components 1.0' ) 013-ZnServer>Connected (SERVER) ZnHeaders('Connection'->'close' 'Content-Length'->'27' 'Content-Type'->'text/plain;charset=utf-8' 'Date'->'Sun, 20 Oct 2013 15:42:53 GMT' 'Server'->'Zinc HTTP Components 1.0' )
FAILED requests log the SERVER headers before the CLIENT headers...
(SERVER) ZnHeaders('Connection'->'close' 'Content-Length'->'27' 'Content-Type'->'text/plain;charset=utf-8' 'Date'->'Sun, 20 Oct 2013 15:42:53 GMT' 'Server'->'Zinc HTTP Components 1.0' ) (CLIENT) ZnHeaders('Accept'->'*/*' 'Connection'->'close' 'Host'->'localhost:1700' 'User-Agent'->'Zinc HTTP Components 1.0' ) 013-ZnServer>Connected
On my system, the problem can be fixed by adding a delay at point "E"
Socket>>waitForAcceptFor: timeout self waitForConnectionFor: timeout ifTimedOut: [^ nil]. "(Delay forMilliseconds: 100) wait. " "<---E" ^ self isConnected ifTrue:[self accept]
and made worse by adding a delay at point "F"
waitForConnectionFor: timeout ifTimedOut: timeoutBlock | startTime msecsDelta msecsEllapsed status | "(Delay forMilliseconds: 200) wait." "<---F" startTime := Time millisecondClockValue. msecsDelta := (timeout * 1000) truncated. status := self primSocketConnectionStatus: socketHandle. [(status = WaitingForConnection) and: [(msecsEllapsed := Time millisecondsSince: startTime) < msecsDelta]] whileTrue: [ semaphore waitTimeoutMSecs: msecsDelta - msecsEllapsed. status := self primSocketConnectionStatus: socketHandle]. status = Connected ifFalse: [^timeoutBlock value]. ^ true
cheers, Ben
Sven Van Caekenberghe wrote:
Ben,
Thanks for spending time looking into this.
Now, you produced an enormous amount of information, but I am still confused.
I have to come back to you when I have more time to rerun my older unfinished experiments using Windows 8.1 in VirtualBox, so that I can reformulate how I see things.
Hopefully I will be able to understand what you were up to ;-)
Sven
On 20 Oct 2013, at 18:38, btc@openinworld.com wrote:
Sven,
I've spent the day poking around in different parts of ZnServers and Sockets and got about as far as I can. I've reported a lot of stuff on the Case [1], and some expert review would now be useful - but you might want to skip to the end where I suggest a way that the problem might be invoked/simulated at your end on an otherwise working Max or Linux system.
cheers -ben
btc@openinworld.com wrote:
While trying to debug this I found the error went away when I put a breakpoint to step through ZnMultiThreadedServer>>executeOneRequestResponseOn: Presuming a race condition I played with adding delays until I managed to isolate the following case...
ZnMultiThreadedServer>>executeOneRequestResponseOn: stream | request response | (Delay forMilliseconds: 30) wait. "<----- <20 fails. >30 succeeds." (request := self readRequestSafely: stream) ifNil: [ ^ true ] ifNotNil: [ response := self handleRequest: request. self augmentResponse: response forRequest: request. self writeResponseSafely: response on: stream. response useConnection: stream. ]. ^ request wantsConnectionClose or: [ response wantsConnectionClose ]
I've got more info coming, so I've raised ticket [1] to continue discussion.
cheers -ben
[1] https://pharo.fogbugz.com/default.asp?11960
Sven Van Caekenberghe wrote:
Ben,
The goal of the test is to confirm that the server returns an error (refuses a request) when any line, in this case the first so called request line, it too long. Hence the artificially constructed URL. Of course, if you make it shorter, at one point it will be short enough so that it no longer fails - but that defeats the purpose of the test ;-)
Now, the problem with this test and 3 other ones that are related, checking the reaction to other limits, is that they pass on Mac and Linux, but fail (randomly) on Windows, when ZdcSocketStream is used instead of SocketStream, currently the default. I have already looked into this, but up to now I failed to find the problem. The Socket class uses a number of primitives which have totally different implementations on the 3 platforms.
Yes, I could use some help, but this is not easy.
I also think there already is an issue for this, but I can't find it.
Sven
On 19 Oct 2013, at 18:54, btc@openinworld.com wrote:
btc@openinworld.com wrote:
>>> In the process of tying to review the slices for a few issues, I downloaded build #30500 Pharo3.0-win.zip from [1]. (Normally I use files.pharo.org but I wanted to ensure it was a "GREEN" build.) However before loading the slice to review I double-checked the baseline test results by running all tests from TestRunner. I had presumed all tests would be green but was surprised by some failures in the result. Well it maybe it has something to do with environment, but it would be nice for it to be clean to help isoalte any errors introduced by the slice under review. Before I log anything on Fogbugz in case someone can advise anything obvious, the Test Runner result is shown below [2].
My platform is 64-bit Windows 7 Home Premium Service Pack 1. I'll try to follow up with more specific info on each line.
cheers -ben
[1] https://ci.inria.fr/pharo/job/Pharo-3.0-Update-Step-4-Publish/566/
[2] FAILURE ZnServerTests >> #testRequestLineTooLong >> I extracted #testRequestLineTooLong to something I can evaluate from Workspace...
| numX url fudge | fudge := 0. numX := ZnConstants maximumLineLength - fudge . (url := ZnUrl fromString: ' http://localhost:1704/ ') addPathSegment: #echo; addPathSegment: (String new: numX withAll: $X). ZnClient new beOneShot; logToTranscript; url: url; get; response
That fails with initial fudge factor of 0 - with 'ZnUnknownHttpVerion.' Here is the Transcript (including logging from ZnServer)... 2013-10-20 00:45:40 489094 D Executing request/response loop 2013-10-20 00:45:40 505527 I Wrote a ZnRequest(GET /echo/XXXXXXXX...XXXXX) 2013-10-20 00:45:40 505527 D Sent headers Accept: */* User-Agent: Zinc HTTP Components 1.0 Connection: close Host: localhost:1704
2013-10-20 00:45:40 489094 D ZnLineTooLong bad request while parsing 2013-10-20 00:45:40 489094 I Wrote a ZnResponse(400 Bad Request text/plain;charset=utf-8 27B) 2013-10-20 00:45:40 489094 D Closing streamZnStatusLine
With a fudge factor of 9 it still fails, but with 10 it succeeds. Interestingly, inspect 'url' shows...
http://localhost:1704/echo/XXXXXXXXXXXXXXXXXXXXXXXXXX...etc
...and 10 characters = 1704/echo/ but then correlation does not equal cause.
How should we proceed?
cheers -ben
>
participants (2)
-
btc＠openinworld.com -
Sven Van Caekenberghe