[hunchentoot-devel] A simple repeatable leak case, LW32 : Re: Terminal problem when writing to binary request thread on LW32/Win32, under load

Thu Feb 11 07:20:34 UTC 2010

Here's my concern.  There are 2 things amiss, that I can trigger
independently. . . .

1.  The errors when using finalize-output or force-output.
2.  The leak

The dumps you see below are from (1)

Should finalize/force-output work?

Complaining of (2) worries me - I don't see anything leaking per se' in
hunchentoot's workings; but am not sure if I could give a leaking
codebase to LW and have them trusting that it isn't the algorithm.

Which symtom(s) should I emphasize to them?

Matt Lamari wrote:
> This leaks (and eventually something bad happens).
>
> I realize that the leadtester may be abusing it; but I'd like to assume
> the worst coming from the net.  Closing the load tester does not
> alleviate the problem.
>
> Note - I've got Linux/SBCL guys telling me this works fine on their
> platforms, without leaks.
>
> Lispworks 5.1 and Lispworks 6
> Hunchentoot, latest supporting libs
> Win32  (I run on Vista 64)
>
>
> Minimalist dispatch table: (works the same in the IDE AND in the
> delivered app)
>
> (setf hunchentoot::*session-max-time* 10) ;remove this as a variable
> (setq *dispatch-table*
>           (append
>            (list
>             (create-prefix-dispatcher
>              "/"
>              (lambda (&rest rest)
>                (let ((stream (send-headers)))
>                  (loop for i from 1 to 10000 do (write-byte 65 stream)))
>                nil)))
>            (list #'default-dispatcher)))
>
> Load tester:  (Note - on Win32 this is a single executable, just drop it
> somewhere and run it)
>
> http://openwebload.sourceforge.net/ 
>
> Command line:
>
> openload.exe http://localhost 100
>
>
> Eventually, it eats up ram and at about 600 meg memory errors start
> coming forth (in the delivered EXE).
>
> I acknowledge this may be something more fundamental with the platform. 
> But I wanted to make sure that I'm using hunchentoot properly, and if
> hunchentoot has anything that would help me narrow down what is happening.
>
> Thank you for your time,
> Matt
>
>
> Matt Lamari wrote:
>   
>> I should probably be more clear - The program goes haywire when I force
>> or finalize-output to this stream.  I acknowledge that, here, I should
>> not do that, and I don't do so on my main web app.
>>
>> However, doing so seems to send the whole environment "off the rails" in
>> a manner similar to what happens to the main app, and I was hoping that
>> someone with more knowledge of what's under the API  could tell whether
>> or not this sort of failure should be contained, or what's going on when
>> this type of failure occurs.
>>
>> Any help appreciated.  I realize I may not have a hunchentoot problem;
>> but that someone who knowns hunchentoot may be able to point me in the
>> right direction.
>>
>> Cheers,
>> Matt
>>
>>
>> Matt Lamari wrote:
>>   
>>     
>>> This is part of a wider effort, to isolate a problem I've been having
>>> with my main app.
>>>
>>> I have written a standalone LW deliverable, all in one directory (with
>>> the libs used in subdirectories).  It builds to an .EXE in LW5.1 or LW6
>>> (2 batch files).
>>>
>>> I can't get the  same feedback running in the IDE, except for the leaks.
>>>
>>> I am posting here to get assistance in converging on the solution.  The
>>> problem I'm hitting may be in libraries, my usage of them, or lispworks
>>> itself (the problem in my wider app seems to trigger
>>> garbage-collector-level problems).
>>>
>>> The load tester is http://openwebload.sourceforge.net/  <-- I can get
>>> the problem to repeat with 1 connection or 100, default settings,
>>> against the dispatcher I listed below.
>>>
>>> It is my understanding that there are 2 ways for a Hunchentoot request
>>> handlers to emit data - returning a string, or by calling (send-headers)
>>> then writing to the returned stream.
>>>
>>> I have a bare-bones hunchentoot server that returns a page that is 100x
>>> the letter A.
>>> If I make it return the 100x A string, it will run indefinitely, and
>>> work fine.
>>> If I make it write binary 65 100 times with force-output, it grenades.
>>>
>>> Against a browser, BOTH WORK FINE.
>>>
>>> Against the load tester, the stream-write version leaks badly (even with
>>> the log turned off), spits a lot of errors, and eventually fails.  The
>>> string version can run indefinitely, without errors or leaks.
>>>
>>> Obviously the load tester is disconnecting.  But the important point is
>>> that it's exposing some scenario that is possible.
>>>
>>> Also, the failures I get in my main app have seemed to happen at the
>>> garbage collector level (a dump will be included below)
>>>
>>> I don't want to sweep this under the rug by accumulating a string, it
>>> may be highlighting a more serious problem in something more fundamental.
>>>
>>> Here is the hunchentoot dispatcher:  The "return 100 As string" is
>>> there, commented out.  Force-output on each byte is there to
>>> aggressively push the problem.  Again let me state - this code works
>>> when interacting with a browser.  And I expect an exception when the
>>> receiver disappears, just not one this critical.
>>>
>>>
>>> (setq *dispatch-table*
>>>           (append
>>>            (list
>>>             (create-prefix-dispatcher
>>>              "/"
>>>              (lambda (&rest rest)
>>>                #| (make-string 100 :initial-element #\A) |#
>>>                (let ((stream (send-headers)))
>>>                  (loop for i from 1 to 100 do (progn (write-byte 65
>>> stream) (force-output stream))))
>>>                (force-output stream)
>>>                nil)))
>>>            (list #'default-dispatcher)))
>>>
>>> This whole directory is self-contained and made of only the most minimal
>>> code (this is most of it) and the ASDF-loads.  It includes a batch file
>>> that can build for LW5 and for LW6.  I can hand it off to any interested
>>> party.  If security is a concern, this core dispatch table is easily
>>> transplantable into anyone's working Hunchentoot environment. . . . 
>>> Note the references to "CFO" and "MARK-GENERATION".
>>>
>>> I can provide the self-contained test project as a zipfile to anyone who
>>> wants it.
>>>
>>>
>>> Here is a sample error:
>>>
>>> *** EXCEPTION DATA ***
>>> code c0000005  flags 00000000 address 2015C250
>>> EIP 2015c250  ESP 032fe62c  EBP 032fe644 ESI 0000002e  EDI 20bbfff2
>>> EAX 00000140  EBX 0e84f0c1  ECX 0000007f EDX 00000100
>>> stack dump:
>>> 032fe62c: 08048020 00001486 28b7bb52 28b7bb42
>>> 032fe63c: 00002e5e 00000480 032fe67c 204f61e3
>>> 032fe64c: 20b33b2d 20250d9b 20250d9b 20250d9b
>>> 032fe65c: 20250d9b 20250d9b 20250d9b 20250d9b
>>> 032fe66c: 20250d9b 00000c86 032fe684 2021142e
>>> 032fe67c: 032fe69c 20463860 08048020 20b33b2d
>>> 032fe68c: 20b33b1b 20746573 20b33b2d 20250d9b
>>> 032fe69c: 032fe6d8 20463c1d 20b33b1b ffffff96
>>> 032fe6ac: 032fe7d4 032fe6d8 20463c73 00000036
>>> 032fe6bc: 00000000 20b33b2d 20004003 2014bd33
>>> 032fe6cc: 20250d9b 200caac7 20b33b1b 032fe700
>>> 032fe6dc: 2046300c 00000084 200caac7 032fe70c
>>> 032fe6ec: 200caac7 200caac7 200caac7 200caac7
>>> 032fe6fc: 200caac7 032fe71c 207a8b92 20b33b1b
>>> 032fe70c: 00000100 00000056 032fe734 200caac7
>>> 032fe71c: 032fe72c 204e9f2e 20b33b1b 20b33b1b
>>> reentrypoint 200705e2
>>> <**> Return address not inside a CFO : 20809a13 at 2efe78c
>>> ;>>>>> dumping   2efe70c  [16] limit 2eff000
>>> ;>  2efe70c:       100 200a3b07  2efe71c 20740488
>>> ;>  2efe71c:   2efe728 204e5469 200a3b07  2efe740
>>> ;>  2efe72c:  204eb9bb       84 fffffff6  2efe810
>>> ;>  2efe73c:  200a3b07  2efe774 204e5622 201fc5c3
>>> ;>  2efe74c:  ffffff96  2efe7fc  2efe774 204e5639
>>> ;>  2efe75c:        36 201fc5c3 20628823 200a3b07
>>> ;>  2efe76c:  200a3b07 200a3ac3  2efe7a0 204aff5a
>>> ;>  2efe77c:         4 ffffff96 20b38561 201fc5c3
>>> ;>  2efe78c:  20809a13 20b385fd       30     3000
>>> ;>  2efe79c:        30  2efe7b8 204ab1b6        0
>>> ;>  2efe7ac:  20b381da 20b28f03 20a0fb2f  2efe7d4
>>> ;>  2efe7bc:  2073e8fe 20b28f03 20591a0b 206578f7
>>> ;>  2efe7cc:   2efe7f1 206e89c7  2efe944 204af6ab
>>> ;>  2efe7dc:        1c 20b28f03 90ff8096 20155383
>>> ;>  2efe7ec:        56 90ff8096 208098fb  2efe7e5
>>> ;>  2efe7fc:  ffffff96  2efe9b4  2efe944 204af738
>>> Simple backtrace:
>>> 04ABFD30 20005170 #<Callable 2000511A>
>>>      >>> Actually called : MARK-GENERATION
>>> 04ABFD3C 2000FACC #<Callable 2000FA1A>
>>> 04ABFD54 2006B742 #<Callable 2006B422>
>>> 04ABFD78 200343DA #<Callable 2003436A>
>>> 04ABFD98 20034926 #<Callable 2003487A>
>>> 033FE384 200345D6 #<Callable 200344A2>
>>>      >>> Actually called : I-FULL-ALLOC-BLOCK-LOCAL
>>> 033FE394 20040EAE #<Callable 20040E8A>
>>>      >>> Actually called : ALLOC-OBJECT
>>> 033FE3B8 2018BD98 "ALLOC-STRING"
>>>      >>> Actually called : MAKE-BASE-STRING
>>> 033FE3D0 201AE864 "IN-MAKE-TYPED-STRING"
>>> 033FE3F8 201AEC11 "MAKE-TYPED-STRING"
>>> 033FE410 207E82E3 "MAKE-STREAM-BLOCK"
>>> 033FE430 207F27F5 "ADD-NEW-BLOCK"
>>> 033FE4BC 207F200D "(METHOD STREAM-FLUSH-BUFFER STRING-OUTPUT-STREAM .  NIL)"
>>>      >>> Actually called : STREAM-FLUSH-BUFFER
>>> 033FE4EC 20173123 "(METHOD STREAM-WRITE-STRING (BUFFERED-STREAM T))"
>>> 033FE518 207556D9 #<Callable 20755622>
>>>      >>> Actually called : STREAM-WRITE-STRING
>>> 033FE540 20176744 "WRITE-STRING*"
>>> 033FE56C 20126821 "SUB-FORMAT"
>>> 033FE5B4 20125E72 "CALL-SUB-FORMAT"
>>> 033FE5D0 2084FE08 "FORMAT"
>>> 033FE674 204B0CE4 "SAFER-FORMAT"
>>> 033FE780 204B04CD "(METHOD DBG-PRINT-FRAME BINDING-FRAME .  NIL)"
>>> 033FE7A8 2073E8FE #<Callable 2073E872>
>>>      >>> Actually called : DBG-PRINT-FRAME
>>> 033FE7D4 204AF6AB "BUG-BACKTRACE"
>>> 033FE944 2044C5FA "PRINT-BACKTRACE-TO-STREAM"
>>> 033FE9AC 208243D0 "GET-BACKTRACE"
>>> 033FEA9C 20403292 "(METHOD HANDLE-REQUEST (ACCEPTOR REQUEST))"
>>> 033FEAB4 204BACC0 "SIGNAL"
>>> 033FEAF4 204CB948 "CONDITIONS-ERROR"
>>> 033FEB38 201EA995 "ERROR"
>>>      >>> Actually called : SOCKET-ERROR
>>> 033FEB48 2043F73B "(METHOD STREAM-WRITE-BUFFER (SOCKET-STREAM T T T))"
>>>      >>> Actually called : STREAM-WRITE-BUFFER
>>> 033FEB6C 20173AE9 "(METHOD STREAM-FLUSH-BUFFER BUFFERED-STREAM .  NIL)"
>>>      >>> Actually called : STREAM-FLUSH-BUFFER
>>> 033FEB88 20173A11 "(METHOD STREAM-FORCE-OUTPUT BUFFERED-STREAM .  NIL)"
>>>      >>> Actually called : FORCE-OUTPUT
>>> 033FEB94 207F21B5 "MAIN"
>>> 033FEBA8 2054562E "(METHOD HANDLE-REQUEST (ACCEPTOR REQUEST))"
>>> 033FEC70 2084A559 "(METHOD PROCESS-REQUEST T .  NIL)"
>>> 033FED08 20409679 "(METHOD PROCESS-CONNECTION (ACCEPTOR T))"
>>> 033FEDBC 20566DF9 "NEXT-METHOD-CALL-2"
>>> 033FEDDC 204F7F37 "(METHOD PROCESS-CONNECTION AROUND (ACCEPTOR T))"
>>> 033FEE88 2076DE2E #<Callable 2076DDEA>
>>> 033FEEA8 2083B4A7 "PROCESS-SG-FUNCTION"
>>> 033FEFBC 204896A2 #<Callable 2048967A>
>>> 033FEFD0 20887C6B "(DEFINE-FOREIGN-CALLABLE NIL) . 
>>> %FOREIGN-CALLABLE/thread_initial_function"
>>>
>>>
>>>
>>>   
>>>     
>>>       
>>   
>>     
>
>   