[hunchentoot-devel] Terminal problem when writing to binary request thread on LW32/Win32, under load
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"
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"
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"
Matt,
The symptoms are the same on LW6 and LW5.1? If the test case is self-contained, I'd suggest to send it to LW support; I'm pretty sure they'd be interested to see it. No matter what you're doing (and I only thought about it for a few seconds), the dump you included looks like one of those thing that should not happen...
Thanks, Edi.
PS: BTW, do you have backtraces enabled in your Hunchentoot? And if so, can you reproduce the problem with them turned off?
On Thu, Feb 11, 2010 at 7:23 AM, Matt Lamari matt.lamari@gmail.com 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"
tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel
All logs disabled, I set backtrace to NIL for good measure.
(Heavy error output + global-lock lead to another degenerative condition that I'm trying to remove from the equation, running out of processes when they all lock trying to get to the log file).
Edi Weitz wrote:
Matt,
The symptoms are the same on LW6 and LW5.1? If the test case is self-contained, I'd suggest to send it to LW support; I'm pretty sure they'd be interested to see it. No matter what you're doing (and I only thought about it for a few seconds), the dump you included looks like one of those thing that should not happen...
Thanks, Edi.
PS: BTW, do you have backtraces enabled in your Hunchentoot? And if so, can you reproduce the problem with them turned off?
On Thu, Feb 11, 2010 at 7:23 AM, Matt Lamari matt.lamari@gmail.com 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"
tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel
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"
On Thu, Feb 11, 2010 at 8:20 AM, Matt Lamari matt.lamari@gmail.com wrote:
Should finalize/force-output work?
For sure it should work...
Which symtom(s) should I emphasize to them?
I don't have the time to look at this in more detail and I'll be out of town for a couple of days, but if you can present them with a self-contained test case that triggers an error in the garbage collector, that should be interesting enough, I'd think.
-
Edi Weitz -
Matt Lamari