I updated https://pharo.fogbugz.com/f/cases/10908/Three-tests-failing-on-Windows-ZnServerTests
On 21 Oct 2013, at 00:58, [email protected] 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, >> [email protected] >> 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 >>> >>> >>> [email protected] >>> 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, >>>>> [email protected] >>>>> wrote: >>>>> >>>>> >> >>>>> [email protected] >>>>> 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 >>>>>> >>>>>> > >>>>>> >>>>>> >>>>> >>>>> >>>>> >>>> >>>> >>>> >>> >> >> >> >> >> >
