-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1

Hello Hans!

I have confirmed the problem both when running on localhost and with seperate machines for client and server. Siege does not act the same way that nmap -sT does. The problem is noticable with nmap because it performs a connect without sending any additional data from the nmap man page I extracted this not so flattery nugget:

Many services on your average Unix system will add a note to syslog, and sometimes a cryptic error message, when Nmap connects and then closes the connection without sending data. Truly pathetic services crash when this happens, though that is uncommon.

I noticed myself that I was unable to provoke the uncaught exception when using a lower number of iterations but it always does this for an iteration count of 20 on my machines. I'm expecting this could vary a little so maybe you could raise the number of iterations slightly to provoke one?

I also did as you suggested and set *break-on-signals*. The trace looks like this:

Socket error in "getpeername": ENOTCONN (Transport endpoint is not connected) BREAK was entered because of *BREAK-ON-SIGNALS* (now rebound to NIL). [Condition of type SIMPLE-CONDITION]

Restarts: 0: [CONTINUE] Return from BREAK. 1: [REASSIGN] Return from BREAK and assign a new value to *BREAK-ON-SIGNALS*. 2: [TERMINATE-THREAD] Terminate this thread (#<THREAD "Hunchentoot listener (*:8000)" RUNNING {AAA8B51}>)

Backtrace: 0: (BREAK "~A~%BREAK was entered because of *BREAK-ON-SIGNALS* ~\n (now rebound to NIL)." #<SB-BSD-SOCKETS:NOT-CONNECTED-ERROR {AE7FCA9}>) 1: (SIGNAL #<SB-BSD-SOCKETS:NOT-CONNECTED-ERROR {AE7FCA9}>)[:EXTERNAL] 2: (ERROR SB-BSD-SOCKETS:NOT-CONNECTED-ERROR)[:EXTERNAL] 3: (SB-BSD-SOCKETS:SOCKET-ERROR "getpeername") 4: (SB-BSD-SOCKETS:SOCKET-ERROR "getpeername")[:EXTERNAL] 5: ((SB-PCL::FAST-METHOD SB-BSD-SOCKETS:SOCKET-PEERNAME (SB-BSD-SOCKETS:SOCKET)) #<unavailable argument> #<unavailable argument> #<SB-BSD-SOCKETS:INET-SOCKET descriptor 6 {AE7F971}>) 6: ((SB-PCL::FAST-METHOD USOCKET:GET-PEER-ADDRESS (USOCKET:STREAM-USOCKET)) #<unavailable argument> #<unavailable argument> #<USOCKET:STREAM-USOCKET {AE7FBD1}>) 7: (HUNCHENTOOT::CLIENT-AS-STRING #<USOCKET:STREAM-USOCKET {AE7FBD1}>) 8: ((SB-PCL::FAST-METHOD HUNCHENTOOT:HANDLE-INCOMING-CONNECTION (HUNCHENTOOT:ONE-THREAD-PER-CONNECTION-TASKMASTER T)) ..) 9: ((SB-PCL::FAST-METHOD HUNCHENTOOT:ACCEPT-CONNECTIONS (HUNCHENTOOT:ACCEPTOR)) #<unavailable argument> #<unavailable argument> #<HUNCHENTOOT:ACCEPTOR (host *, port 8000)>) 10: ((FLET SB-THREAD::WITH-MUTEX-THUNK)) 11: ((FLET #:WITHOUT-INTERRUPTS-BODY-[CALL-WITH-MUTEX]477)) 12: (SB-THREAD::CALL-WITH-MUTEX ..) 13: ((LAMBDA ())) 14: ("foreign function: #x806480C") 15: ("foreign function: #x8052C21") 16: ("foreign function: #x805BD9D") 17: ("foreign function: #xB7FB84C0")

I had a quick peek at client-as-string and it does indeed not handle the sb-bsd-sockets:not-connected-error and if I put a handler-case around body of client-as-string returning nil when the exception appears I can not reproduce my problem anymore.

This wouldn't provide a portable solution though :-P

/Peter

Hans Hübner wrote:

Peter,

I am not able to reproduce the problem using the nmap command line that you provided. I also ran siege against Hunchentoot:

Transactions: 1205 hits Availability: 100.00 % Elapsed time: 14.40 secs Data transferred: 3.03 MB Response time: 0.11 secs Transaction rate: 83.69 trans/sec Throughput: 0.21 MB/sec Concurrency: 9.30 Successful transactions: 1205 Failed transactions: 0 Longest transaction: 6.29 Shortest transaction: 0.01

Can you reproduce the problem with siege? What platform are you running on? Can you reproduce the problem when the client is on the same machine as the server?

It'd be interested to learn where the SB-BSD-SOCKETS:NOT-CONNECTED-ERROR is actually signalled from. To debug, you might set *BREAK-ON-SIGNALS* to 'SB-BSD-SOCKETS:NOT-CONNECTED-ERROR and post the backtrace.

-Hans

2009/7/3 Peter Stiernström peter.stiernstrom@blixtvik.se: I don't know if this have come up earlier or if it is a known problem. If so I am sorry for bringing it up again. A quick look through the archives turned up a non-caught sbcl socket timeout error with the obvious fix of adding an error translation to the usocket sbcl backend error map. I expect this to be somewhat similar.

When stressing hunchentoot with a number of connection like so:

for i in $(seq 1 20); do nmap -sT -p 80 <hostname> ;done

Hunchentoot (last 1.0 release) stops responding after not having caught a SB-BSD-SOCKETS:NOT-CONNECTED-ERROR thus being easily DOSed.

I was hoping that there would be an obvious similar mapping missing but I don't know my way around hunchentoot to figure out what to map SB-BSD-SOCKETS:NOT-CONNECTED-ERROR to.

I am seeing this problem on a regular basis and for now it always prompts a full restart.

I am using usocket 0.4.1 with hunchentoot 1.0.0.

/Peter

...

_______________________________________________ tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

...

---

tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

- -- Med vänlig hälsning,

Peter Stiernström 0708-810932 Blixtvik AB

-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1

Hi Hans,

Hans Hübner wrote:

Hi Peter,

2009/7/6 Peter Stiernström peter.stiernstrom@blixtvik.se

...

I had a quick peek at client-as-string and it does indeed not handle the sb-bsd-sockets:not-connected-error and if I put a handler-case around body of client-as-string returning nil when the exception appears I can not reproduce my problem anymore.

This wouldn't provide a portable solution though :-P

This really is a bug that requires fixing in usocket. There are multiple issues:

• As shown in the backtrace, the problem is that the getpeername()

call fails for a socket that is not connected anymore. SBCL does the right thing by signalling a condition. Other implementations (I checked CCL) seem to behave differently, i.e. return NIL in such a case.

• Usocket does not unify the behavior, so the implementation specific

condition percolates to the caller, Hunchentoot in this case.

• Hunchentoot is not prepared to handle conditions when creating a new

worker thread. The call to CLIENT-AS-STRING is made when creating the name for the handler process of a new incoming connection, and that is done in the context of the server thread. Therefore, the signalled condition will stop the acceptor process.

I spent some thoughts on how a "portable solution" would look like, but given that the Lisp implementations vary greatly in behavior, fixing usocket would be a pretty large task that I don't have the time to do right now. Thus, I would propose this patch:

http://bknr.net/trac/changeset/4428?format=diff&new=4428

It handles all conditions that are signaled during worker process creation, under the theory that we want to prevent the acceptor process from crashing under all circumstances. This is not a clean solution in that it may paper over bugs, but given the limited number of function invocations that are surrounded by a HANDLER-CASE, I'd say that this is a proper intermediate fix.

Please give it a try and let me know if it solves the problem for you.

I tried your suggested patch but I can't seem to be able to get it to catch the exception for me. Were you able to duplicate the error yourself to verify that the suggested patch does indeed work? Since I am using the 1.0.0 hunchentoot release I couldn't just apply your patch but added the handler-case by hand and thus ended up with this in taskmaster.lisp:

(defmethod handle-incoming-connection ((taskmaster one-thread-per-connection-taskmaster) handle) (incf *worker-counter*) ;; check if we need to perform a global GC (when (and *cleanup-interval* (zerop (mod *worker-counter* *cleanup-interval*))) (when *cleanup-function* (funcall *cleanup-function*))) (handler-case (mp:process-run-function (format nil "Hunchentoot worker (client: ~{~A:~A~})" (multiple-value-list (get-peer-address-and-port handle))) nil #'process-connection (taskmaster-acceptor taskmaster) handle) (error (cond) (log-message *lisp-errors-log-level* "Error while creating worker thread for new incoming connection: ~A" cond))))

/Peter

-Hans

---

tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

- -- Med vänlig hälsning,

Peter Stiernström 0708-810932 Blixtvik AB

-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1

Hans,

I should have realised I was editing the lispworks implementation myself had I only had a cup of coffee this morning :-P

Now when I tried your patch out I still get hangups but this is another kind of hangup:

debugger invoked on a UNBOUND-VARIABLE in thread #<THREAD "Hunchentoot listener (*:8000)" RUNNING {AD467D1}>: The variable HUNCHENTOOT:*ACCEPTOR* is unbound.

I am trying this out with the hunchentoot default page by the way.

/Peter

Hans Hübner wrote:

Peter,

sorry, I am not able to reproduce the problem myself, so I made the patch blindly and made a mistake, working on the Lispworks code rather than the portable code that affects you. Please look at the first hunk of this diff:

http://bknr.net/trac/changeset/4430?format=diff&new=4430

and let me know if that does it for you.

Sorry, Hans

On Mon, Jul 6, 2009 at 11:09, Peter Stiernströmpeter.stiernstrom@blixtvik.se wrote: Hi Hans,

Hans Hübner wrote:

...

...

...

Hi Peter,

2009/7/6 Peter Stiernström peter.stiernstrom@blixtvik.se

...

I had a quick peek at client-as-string and it does indeed not handle the sb-bsd-sockets:not-connected-error and if I put a handler-case around body of client-as-string returning nil when the exception appears I can not reproduce my problem anymore.

This wouldn't provide a portable solution though :-P

This really is a bug that requires fixing in usocket. There are multiple issues:

• As shown in the backtrace, the problem is that the getpeername()

call fails for a socket that is not connected anymore. SBCL does the right thing by signalling a condition. Other implementations (I checked CCL) seem to behave differently, i.e. return NIL in such a case.

• Usocket does not unify the behavior, so the implementation specific

condition percolates to the caller, Hunchentoot in this case.

• Hunchentoot is not prepared to handle conditions when creating a new

worker thread. The call to CLIENT-AS-STRING is made when creating the name for the handler process of a new incoming connection, and that is done in the context of the server thread. Therefore, the signalled condition will stop the acceptor process.

I spent some thoughts on how a "portable solution" would look like, but given that the Lisp implementations vary greatly in behavior, fixing usocket would be a pretty large task that I don't have the time to do right now. Thus, I would propose this patch:

http://bknr.net/trac/changeset/4428?format=diff&new=4428

It handles all conditions that are signaled during worker process creation, under the theory that we want to prevent the acceptor process from crashing under all circumstances. This is not a clean solution in that it may paper over bugs, but given the limited number of function invocations that are surrounded by a HANDLER-CASE, I'd say that this is a proper intermediate fix.

Please give it a try and let me know if it solves the problem for you.

I tried your suggested patch but I can't seem to be able to get it to catch the exception for me. Were you able to duplicate the error yourself to verify that the suggested patch does indeed work? Since I am using the 1.0.0 hunchentoot release I couldn't just apply your patch but added the handler-case by hand and thus ended up with this in taskmaster.lisp:

(defmethod handle-incoming-connection ((taskmaster one-thread-per-connection-taskmaster) handle) (incf *worker-counter*) ;; check if we need to perform a global GC (when (and *cleanup-interval* (zerop (mod *worker-counter* *cleanup-interval*))) (when *cleanup-function* (funcall *cleanup-function*))) (handler-case (mp:process-run-function (format nil "Hunchentoot worker (client: ~{~A:~A~})" (multiple-value-list (get-peer-address-and-port handle))) nil #'process-connection (taskmaster-acceptor taskmaster) handle) (error (cond) (log-message *lisp-errors-log-level* "Error while creating worker thread for new incoming connection: ~A" cond))))

/Peter

...

...

...

-Hans

---

tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

_______________________________________________ tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

...

---

tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

- -- Med vänlig hälsning,

Peter Stiernström 0708-810932 Blixtvik AB

-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1

Hello Hans,

Hans Hübner wrote:

Peter, as I cannot reproduce the problem myself, can you please post a stack backtrace? Thanks!

The variable HUNCHENTOOT:*ACCEPTOR* is unbound. BREAK was entered because of *BREAK-ON-SIGNALS* (now rebound to NIL). [Condition of type SIMPLE-CONDITION]

Restarts: 0: [CONTINUE] Return from BREAK. 1: [REASSIGN] Return from BREAK and assign a new value to *BREAK-ON-SIGNALS*. 2: [TERMINATE-THREAD] Terminate this thread (#<THREAD "Hunchentoot listener (*:8000)" RUNNING {C42AAE9}>)

Backtrace: 0: (BREAK "~A~%BREAK was entered because of *BREAK-ON-SIGNALS* ~\n (now rebound to NIL)." #<UNBOUND-VARIABLE *ACCEPTOR* {AD37FC1}>) 1: (SIGNAL #<UNBOUND-VARIABLE *ACCEPTOR* {AD37FC1}>)[:EXTERNAL] 2: (ERROR UNBOUND-VARIABLE)[:EXTERNAL] 3: (SB-KERNEL::UNBOUND-SYMBOL-ERROR-HANDLER #<unavailable argument> #.(SB-SYS:INT-SAP #XB5DFFEF0) #<SB-ALIEN-INTERNALS:ALIEN-VALUE :SAP #XB5DFFBDC :TYPE (* (STRUCT SB-VM::OS-CONTEXT-T-STRUCT))> (14)) 4: (SB-KERNEL::UNBOUND-SYMBOL-ERROR-HANDLER #<unavailable argument> #.(SB-SYS:INT-SAP #XB5DFFEF0) #<SB-ALIEN-INTERNALS:ALIEN-VALUE :SAP #XB5DFFBDC :TYPE (* (STRUCT SB-VM::OS-CONTEXT-T-STRUCT))> (14))[:EX.. 5: (SB-KERNEL:INTERNAL-ERROR #.(SB-SYS:INT-SAP #XB5DFFBDC) #<unavailable argument>) 6: ("foreign function: #x806480C") 7: ("foreign function: #x8052BCC") 8: ("foreign function: #x8056BD3") 9: (HUNCHENTOOT:LOG-MESSAGE :ERROR "Error while creating worker thread for new incoming connection: ~A")[:EXTERNAL] 10: ((SB-PCL::FAST-METHOD HUNCHENTOOT:HANDLE-INCOMING-CONNECTION (HUNCHENTOOT:ONE-THREAD-PER-CONNECTION-TASKMASTER T)) ..) 11: ((SB-PCL::FAST-METHOD HUNCHENTOOT:ACCEPT-CONNECTIONS (HUNCHENTOOT:ACCEPTOR)) #<unavailable argument> #<unavailable argument> #<HUNCHENTOOT:ACCEPTOR (host *, port 8000)>) 12: ((FLET SB-THREAD::WITH-MUTEX-THUNK)) 13: ((FLET #:WITHOUT-INTERRUPTS-BODY-[CALL-WITH-MUTEX]477)) 14: (SB-THREAD::CALL-WITH-MUTEX ..) 15: ((LAMBDA ())) 16: ("foreign function: #x806480C") 17: ("foreign function: #x8052C21") 18: ("foreign function: #x805BD9D") 19: ("foreign function: #xB7FB84C0")

I found that not attempting to log a message solved this remaining problem.

Thank you very much for your help!

/Peter

2009/7/6 Peter Stiernström peter.stiernstrom@blixtvik.se: Hans,

I should have realised I was editing the lispworks implementation myself had I only had a cup of coffee this morning :-P

Now when I tried your patch out I still get hangups but this is another kind of hangup:

debugger invoked on a UNBOUND-VARIABLE in thread #<THREAD "Hunchentoot listener (*:8000)" RUNNING {AD467D1}>: The variable HUNCHENTOOT:*ACCEPTOR* is unbound.

I am trying this out with the hunchentoot default page by the way.

/Peter

Hans Hübner wrote:

...

...

...

Peter,

sorry, I am not able to reproduce the problem myself, so I made the patch blindly and made a mistake, working on the Lispworks code rather than the portable code that affects you. Please look at the first hunk of this diff:

http://bknr.net/trac/changeset/4430?format=diff&new=4430

and let me know if that does it for you.

Sorry, Hans

On Mon, Jul 6, 2009 at 11:09, Peter Stiernströmpeter.stiernstrom@blixtvik.se wrote: Hi Hans,

Hans Hübner wrote:

...

...

> Hi Peter, > > 2009/7/6 Peter Stiernström peter.stiernstrom@blixtvik.se >> I had a quick peek at client-as-string and it does indeed not handle the >> sb-bsd-sockets:not-connected-error and if I put a handler-case around >> body of client-as-string returning nil when the exception appears I can >> not reproduce my problem anymore. >> >> This wouldn't provide a portable solution though :-P > This really is a bug that requires fixing in usocket. There are > multiple issues: > > - As shown in the backtrace, the problem is that the getpeername() > call fails for a socket that is not connected anymore. SBCL does the > right thing by signalling a condition. Other implementations (I > checked CCL) seem to behave differently, i.e. return NIL in such a > case. > > - Usocket does not unify the behavior, so the implementation specific > condition percolates to the caller, Hunchentoot in this case. > > - Hunchentoot is not prepared to handle conditions when creating a new > worker thread. The call to CLIENT-AS-STRING is made when creating the > name for the handler process of a new incoming connection, and that is > done in the context of the server thread. Therefore, the signalled > condition will stop the acceptor process. > > I spent some thoughts on how a "portable solution" would look like, > but given that the Lisp implementations vary greatly in behavior, > fixing usocket would be a pretty large task that I don't have the time > to do right now. Thus, I would propose this patch: > > http://bknr.net/trac/changeset/4428?format=diff&new=4428 > > It handles all conditions that are signaled during worker process > creation, under the theory that we want to prevent the acceptor > process from crashing under all circumstances. This is not a clean > solution in that it may paper over bugs, but given the limited number > of function invocations that are surrounded by a HANDLER-CASE, I'd say > that this is a proper intermediate fix. > > Please give it a try and let me know if it solves the problem for you.

I tried your suggested patch but I can't seem to be able to get it to catch the exception for me. Were you able to duplicate the error yourself to verify that the suggested patch does indeed work? Since I am using the 1.0.0 hunchentoot release I couldn't just apply your patch but added the handler-case by hand and thus ended up with this in taskmaster.lisp:

(defmethod handle-incoming-connection ((taskmaster one-thread-per-connection-taskmaster) handle) (incf *worker-counter*) ;; check if we need to perform a global GC (when (and *cleanup-interval* (zerop (mod *worker-counter* *cleanup-interval*))) (when *cleanup-function* (funcall *cleanup-function*))) (handler-case (mp:process-run-function (format nil "Hunchentoot worker (client: ~{~A:~A~})" (multiple-value-list (get-peer-address-and-port handle))) nil #'process-connection (taskmaster-acceptor taskmaster) handle) (error (cond) (log-message *lisp-errors-log-level* "Error while creating worker thread for new incoming connection: ~A" cond))))

/Peter

...

...

> -Hans > > _______________________________________________ > tbnl-devel site list > tbnl-devel@common-lisp.net > http://common-lisp.net/mailman/listinfo/tbnl-devel

---

tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

...

...

...

---

tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

_______________________________________________ tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

...

---

tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

- -- Med vänlig hälsning,

Peter Stiernström 0708-810932 Blixtvik AB

-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1

Hans Hübner wrote:

Peter,

try this:

http://bknr.net/trac/changeset/4434?format=diff&new=4434

Hello Hans,

I still get an unbound-variable condition for hunchentoot:*acceptor* but the trace look a bit different:

The variable HUNCHENTOOT:*ACCEPTOR* is unbound. BREAK was entered because of *BREAK-ON-SIGNALS* (now rebound to NIL). [Condition of type SIMPLE-CONDITION]

Restarts: 0: [CONTINUE] Return from BREAK. 1: [REASSIGN] Return from BREAK and assign a new value to *BREAK-ON-SIGNALS*. 2: [TERMINATE-THREAD] Terminate this thread (#<THREAD "Hunchentoot worker (client: 127.0.0.1:46427)" RUNNING {AF2EA11}>)

Backtrace: 0: (BREAK "~A~%BREAK was entered because of *BREAK-ON-SIGNALS* ~\n (now rebound to NIL)." #<UNBOUND-VARIABLE *ACCEPTOR* {AF30361}>) 1: (SIGNAL #<UNBOUND-VARIABLE *ACCEPTOR* {AF30361}>)[:EXTERNAL] 2: (ERROR UNBOUND-VARIABLE)[:EXTERNAL] 3: (SB-KERNEL::UNBOUND-SYMBOL-ERROR-HANDLER #<unavailable argument> #.(SB-SYS:INT-SAP #XB5724028) #<SB-ALIEN-INTERNALS:ALIEN-VALUE :SAP #XB5723CDC :TYPE (* (STRUCT SB-VM::OS-CONTEXT-T-STRUCT))> (14)) 4: (SB-KERNEL::UNBOUND-SYMBOL-ERROR-HANDLER #<unavailable argument> #.(SB-SYS:INT-SAP #XB5724028) #<SB-ALIEN-INTERNALS:ALIEN-VALUE :SAP #XB5723CDC :TYPE (* (STRUCT SB-VM::OS-CONTEXT-T-STRUCT))> (14))[:EX.. 5: (SB-KERNEL:INTERNAL-ERROR #.(SB-SYS:INT-SAP #XB5723CDC) #<unavailable argument>) 6: ("foreign function: #x806480C") 7: ("foreign function: #x8052BCC") 8: ("foreign function: #x8056BD3") 9: ((LAMBDA ())) 10: ((FLET SB-THREAD::WITH-MUTEX-THUNK)) 11: ((FLET #:WITHOUT-INTERRUPTS-BODY-[CALL-WITH-MUTEX]477)) 12: (SB-THREAD::CALL-WITH-MUTEX ..) 13: ((LAMBDA ())) 14: ("foreign function: #x806480C") 15: ("foreign function: #x8052C21") 16: ("foreign function: #x805BD9D") 17: ("foreign function: #xB7FB84C0")

I did set *break-on-signals* to 'unbound-variable and my modified function now looks like this:

(defmethod handle-incoming-connection ((taskmaster one-thread-per-connection-taskmaster) socket) (let ((*acceptor* (taskmaster-acceptor taskmaster))) (handler-case (bt:make-thread (lambda () (process-connection *acceptor* socket)) :name (format nil "Hunchentoot worker (client: ~A)" (client-as-string socket))) (error (e) (log-message *lisp-errors-log-level* "Error while creating worker thread for new incoming connection: ~A" e)))))

/Peter

-Hans

On Mon, Jul 6, 2009 at 13:21, Peter Stiernströmpeter.stiernstrom@blixtvik.se wrote: Hello Hans,

Hans Hübner wrote:

...

...

...

Peter, as I cannot reproduce the problem myself, can you please post a stack backtrace? Thanks!

The variable HUNCHENTOOT:*ACCEPTOR* is unbound. BREAK was entered because of *BREAK-ON-SIGNALS* (now rebound to NIL). [Condition of type SIMPLE-CONDITION]

Restarts: 0: [CONTINUE] Return from BREAK. 1: [REASSIGN] Return from BREAK and assign a new value to *BREAK-ON-SIGNALS*. 2: [TERMINATE-THREAD] Terminate this thread (#<THREAD "Hunchentoot listener (*:8000)" RUNNING {C42AAE9}>)

Backtrace: 0: (BREAK "~A~%BREAK was entered because of *BREAK-ON-SIGNALS* ~\n (now rebound to NIL)." #<UNBOUND-VARIABLE *ACCEPTOR* {AD37FC1}>) 1: (SIGNAL #<UNBOUND-VARIABLE *ACCEPTOR* {AD37FC1}>)[:EXTERNAL] 2: (ERROR UNBOUND-VARIABLE)[:EXTERNAL] 3: (SB-KERNEL::UNBOUND-SYMBOL-ERROR-HANDLER #<unavailable argument> #.(SB-SYS:INT-SAP #XB5DFFEF0) #<SB-ALIEN-INTERNALS:ALIEN-VALUE :SAP #XB5DFFBDC :TYPE (* (STRUCT SB-VM::OS-CONTEXT-T-STRUCT))> (14)) 4: (SB-KERNEL::UNBOUND-SYMBOL-ERROR-HANDLER #<unavailable argument> #.(SB-SYS:INT-SAP #XB5DFFEF0) #<SB-ALIEN-INTERNALS:ALIEN-VALUE :SAP #XB5DFFBDC :TYPE (* (STRUCT SB-VM::OS-CONTEXT-T-STRUCT))> (14))[:EX.. 5: (SB-KERNEL:INTERNAL-ERROR #.(SB-SYS:INT-SAP #XB5DFFBDC) #<unavailable argument>) 6: ("foreign function: #x806480C") 7: ("foreign function: #x8052BCC") 8: ("foreign function: #x8056BD3") 9: (HUNCHENTOOT:LOG-MESSAGE :ERROR "Error while creating worker thread for new incoming connection: ~A")[:EXTERNAL] 10: ((SB-PCL::FAST-METHOD HUNCHENTOOT:HANDLE-INCOMING-CONNECTION (HUNCHENTOOT:ONE-THREAD-PER-CONNECTION-TASKMASTER T)) ..) 11: ((SB-PCL::FAST-METHOD HUNCHENTOOT:ACCEPT-CONNECTIONS (HUNCHENTOOT:ACCEPTOR)) #<unavailable argument> #<unavailable argument> #<HUNCHENTOOT:ACCEPTOR (host *, port 8000)>) 12: ((FLET SB-THREAD::WITH-MUTEX-THUNK)) 13: ((FLET #:WITHOUT-INTERRUPTS-BODY-[CALL-WITH-MUTEX]477)) 14: (SB-THREAD::CALL-WITH-MUTEX ..) 15: ((LAMBDA ())) 16: ("foreign function: #x806480C") 17: ("foreign function: #x8052C21") 18: ("foreign function: #x805BD9D") 19: ("foreign function: #xB7FB84C0")

I found that not attempting to log a message solved this remaining problem.

Thank you very much for your help!

/Peter

...

...

...

2009/7/6 Peter Stiernström peter.stiernstrom@blixtvik.se: Hans,

I should have realised I was editing the lispworks implementation myself had I only had a cup of coffee this morning :-P

Now when I tried your patch out I still get hangups but this is another kind of hangup:

debugger invoked on a UNBOUND-VARIABLE in thread #<THREAD "Hunchentoot listener (*:8000)" RUNNING {AD467D1}>: The variable HUNCHENTOOT:*ACCEPTOR* is unbound.

I am trying this out with the hunchentoot default page by the way.

/Peter

Hans Hübner wrote:

...

...

> Peter, > > sorry, I am not able to reproduce the problem myself, so I made the > patch blindly and made a mistake, working on the Lispworks code rather > than the portable code that affects you. Please look at the first > hunk of this diff: > > http://bknr.net/trac/changeset/4430?format=diff&new=4430 > > and let me know if that does it for you. > > Sorry, > Hans > > On Mon, Jul 6, 2009 at 11:09, Peter > Stiernströmpeter.stiernstrom@blixtvik.se wrote: > Hi Hans, > > Hans Hübner wrote: >>>> Hi Peter, >>>> >>>> 2009/7/6 Peter Stiernström peter.stiernstrom@blixtvik.se >>>>> I had a quick peek at client-as-string and it does indeed not handle the >>>>> sb-bsd-sockets:not-connected-error and if I put a handler-case around >>>>> body of client-as-string returning nil when the exception appears I can >>>>> not reproduce my problem anymore. >>>>> >>>>> This wouldn't provide a portable solution though :-P >>>> This really is a bug that requires fixing in usocket. There are >>>> multiple issues: >>>> >>>> - As shown in the backtrace, the problem is that the getpeername() >>>> call fails for a socket that is not connected anymore. SBCL does the >>>> right thing by signalling a condition. Other implementations (I >>>> checked CCL) seem to behave differently, i.e. return NIL in such a >>>> case. >>>> >>>> - Usocket does not unify the behavior, so the implementation specific >>>> condition percolates to the caller, Hunchentoot in this case. >>>> >>>> - Hunchentoot is not prepared to handle conditions when creating a new >>>> worker thread. The call to CLIENT-AS-STRING is made when creating the >>>> name for the handler process of a new incoming connection, and that is >>>> done in the context of the server thread. Therefore, the signalled >>>> condition will stop the acceptor process. >>>> >>>> I spent some thoughts on how a "portable solution" would look like, >>>> but given that the Lisp implementations vary greatly in behavior, >>>> fixing usocket would be a pretty large task that I don't have the time >>>> to do right now. Thus, I would propose this patch: >>>> >>>> http://bknr.net/trac/changeset/4428?format=diff&new=4428 >>>> >>>> It handles all conditions that are signaled during worker process >>>> creation, under the theory that we want to prevent the acceptor >>>> process from crashing under all circumstances. This is not a clean >>>> solution in that it may paper over bugs, but given the limited number >>>> of function invocations that are surrounded by a HANDLER-CASE, I'd say >>>> that this is a proper intermediate fix. >>>> >>>> Please give it a try and let me know if it solves the problem for you. > I tried your suggested patch but I can't seem to be able to get it to > catch the exception for me. Were you able to duplicate the error > yourself to verify that the suggested patch does indeed work? Since I am > using the 1.0.0 hunchentoot release I couldn't just apply your patch but > added the handler-case by hand and thus ended up with this in > taskmaster.lisp: > > (defmethod handle-incoming-connection ((taskmaster > one-thread-per-connection-taskmaster) handle) > (incf *worker-counter*) > ;; check if we need to perform a global GC > (when (and *cleanup-interval* > (zerop (mod *worker-counter* *cleanup-interval*))) > (when *cleanup-function* > (funcall *cleanup-function*))) > (handler-case > (mp:process-run-function (format nil "Hunchentoot worker (client: > ~{~A:~A~})" > (multiple-value-list > (get-peer-address-and-port handle))) > nil #'process-connection > (taskmaster-acceptor taskmaster) handle) > (error (cond) > (log-message *lisp-errors-log-level* > "Error while creating worker thread for new incoming > connection: ~A" cond)))) > > /Peter > > >>>> -Hans >>>> >>>> _______________________________________________ >>>> tbnl-devel site list >>>> tbnl-devel@common-lisp.net >>>> http://common-lisp.net/mailman/listinfo/tbnl-devel

---

tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

...

...

> _______________________________________________ > tbnl-devel site list > tbnl-devel@common-lisp.net > http://common-lisp.net/mailman/listinfo/tbnl-devel

---

tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

...

...

...

---

tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

_______________________________________________ tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

...

---

tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

- -- Med vänlig hälsning,

Peter Stiernström 0708-810932 Blixtvik AB

-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1

Hans Hübner wrote:

Oh well, *ACCEPTOR* was not inherited by the new process, so use this:

http://bknr.net/trac/changeset/4435?format=diff&new=4435

That seems to fix the last issue I had! Thanks a lot for your time Hans. Should one raise this issue to the attention of the usocket developers though?

/Peter

-Hans

On Mon, Jul 6, 2009 at 13:53, Peter Stiernströmpeter.stiernstrom@blixtvik.se wrote: Hans Hübner wrote:

...

...

...

Peter,

try this:

http://bknr.net/trac/changeset/4434?format=diff&new=4434

Hello Hans,

I still get an unbound-variable condition for hunchentoot:*acceptor* but the trace look a bit different:

The variable HUNCHENTOOT:*ACCEPTOR* is unbound. BREAK was entered because of *BREAK-ON-SIGNALS* (now rebound to NIL). [Condition of type SIMPLE-CONDITION]

Restarts: 0: [CONTINUE] Return from BREAK. 1: [REASSIGN] Return from BREAK and assign a new value to *BREAK-ON-SIGNALS*. 2: [TERMINATE-THREAD] Terminate this thread (#<THREAD "Hunchentoot worker (client: 127.0.0.1:46427)" RUNNING {AF2EA11}>)

Backtrace: 0: (BREAK "~A~%BREAK was entered because of *BREAK-ON-SIGNALS* ~\n (now rebound to NIL)." #<UNBOUND-VARIABLE *ACCEPTOR* {AF30361}>) 1: (SIGNAL #<UNBOUND-VARIABLE *ACCEPTOR* {AF30361}>)[:EXTERNAL] 2: (ERROR UNBOUND-VARIABLE)[:EXTERNAL] 3: (SB-KERNEL::UNBOUND-SYMBOL-ERROR-HANDLER #<unavailable argument> #.(SB-SYS:INT-SAP #XB5724028) #<SB-ALIEN-INTERNALS:ALIEN-VALUE :SAP #XB5723CDC :TYPE (* (STRUCT SB-VM::OS-CONTEXT-T-STRUCT))> (14)) 4: (SB-KERNEL::UNBOUND-SYMBOL-ERROR-HANDLER #<unavailable argument> #.(SB-SYS:INT-SAP #XB5724028) #<SB-ALIEN-INTERNALS:ALIEN-VALUE :SAP #XB5723CDC :TYPE (* (STRUCT SB-VM::OS-CONTEXT-T-STRUCT))> (14))[:EX.. 5: (SB-KERNEL:INTERNAL-ERROR #.(SB-SYS:INT-SAP #XB5723CDC) #<unavailable argument>) 6: ("foreign function: #x806480C") 7: ("foreign function: #x8052BCC") 8: ("foreign function: #x8056BD3") 9: ((LAMBDA ())) 10: ((FLET SB-THREAD::WITH-MUTEX-THUNK)) 11: ((FLET #:WITHOUT-INTERRUPTS-BODY-[CALL-WITH-MUTEX]477)) 12: (SB-THREAD::CALL-WITH-MUTEX ..) 13: ((LAMBDA ())) 14: ("foreign function: #x806480C") 15: ("foreign function: #x8052C21") 16: ("foreign function: #x805BD9D") 17: ("foreign function: #xB7FB84C0")

I did set *break-on-signals* to 'unbound-variable and my modified function now looks like this:

(defmethod handle-incoming-connection ((taskmaster one-thread-per-connection-taskmaster) socket) (let ((*acceptor* (taskmaster-acceptor taskmaster))) (handler-case (bt:make-thread (lambda () (process-connection *acceptor* socket)) :name (format nil "Hunchentoot worker (client: ~A)" (client-as-string socket))) (error (e) (log-message *lisp-errors-log-level* "Error while creating worker thread for new incoming connection: ~A" e)))))

/Peter

...

...

...

-Hans

On Mon, Jul 6, 2009 at 13:21, Peter Stiernströmpeter.stiernstrom@blixtvik.se wrote: Hello Hans,

Hans Hübner wrote:

...

...

> Peter, as I cannot reproduce the problem myself, can you please post a > stack backtrace? Thanks!

The variable HUNCHENTOOT:*ACCEPTOR* is unbound. BREAK was entered because of *BREAK-ON-SIGNALS* (now rebound to NIL). [Condition of type SIMPLE-CONDITION]

Restarts: 0: [CONTINUE] Return from BREAK. 1: [REASSIGN] Return from BREAK and assign a new value to *BREAK-ON-SIGNALS*. 2: [TERMINATE-THREAD] Terminate this thread (#<THREAD "Hunchentoot listener (*:8000)" RUNNING {C42AAE9}>)

Backtrace: 0: (BREAK "~A~%BREAK was entered because of *BREAK-ON-SIGNALS* ~\n (now rebound to NIL)." #<UNBOUND-VARIABLE *ACCEPTOR* {AD37FC1}>) 1: (SIGNAL #<UNBOUND-VARIABLE *ACCEPTOR* {AD37FC1}>)[:EXTERNAL] 2: (ERROR UNBOUND-VARIABLE)[:EXTERNAL] 3: (SB-KERNEL::UNBOUND-SYMBOL-ERROR-HANDLER #<unavailable argument> #.(SB-SYS:INT-SAP #XB5DFFEF0) #<SB-ALIEN-INTERNALS:ALIEN-VALUE :SAP #XB5DFFBDC :TYPE (* (STRUCT SB-VM::OS-CONTEXT-T-STRUCT))> (14)) 4: (SB-KERNEL::UNBOUND-SYMBOL-ERROR-HANDLER #<unavailable argument> #.(SB-SYS:INT-SAP #XB5DFFEF0) #<SB-ALIEN-INTERNALS:ALIEN-VALUE :SAP #XB5DFFBDC :TYPE (* (STRUCT SB-VM::OS-CONTEXT-T-STRUCT))> (14))[:EX.. 5: (SB-KERNEL:INTERNAL-ERROR #.(SB-SYS:INT-SAP #XB5DFFBDC) #<unavailable argument>) 6: ("foreign function: #x806480C") 7: ("foreign function: #x8052BCC") 8: ("foreign function: #x8056BD3") 9: (HUNCHENTOOT:LOG-MESSAGE :ERROR "Error while creating worker thread for new incoming connection: ~A")[:EXTERNAL] 10: ((SB-PCL::FAST-METHOD HUNCHENTOOT:HANDLE-INCOMING-CONNECTION (HUNCHENTOOT:ONE-THREAD-PER-CONNECTION-TASKMASTER T)) ..) 11: ((SB-PCL::FAST-METHOD HUNCHENTOOT:ACCEPT-CONNECTIONS (HUNCHENTOOT:ACCEPTOR)) #<unavailable argument> #<unavailable argument> #<HUNCHENTOOT:ACCEPTOR (host *, port 8000)>) 12: ((FLET SB-THREAD::WITH-MUTEX-THUNK)) 13: ((FLET #:WITHOUT-INTERRUPTS-BODY-[CALL-WITH-MUTEX]477)) 14: (SB-THREAD::CALL-WITH-MUTEX ..) 15: ((LAMBDA ())) 16: ("foreign function: #x806480C") 17: ("foreign function: #x8052C21") 18: ("foreign function: #x805BD9D") 19: ("foreign function: #xB7FB84C0")

I found that not attempting to log a message solved this remaining problem.

Thank you very much for your help!

/Peter

...

...

> 2009/7/6 Peter Stiernström peter.stiernstrom@blixtvik.se: > Hans, > > I should have realised I was editing the lispworks implementation myself > had I only had a cup of coffee this morning :-P > > Now when I tried your patch out I still get hangups but this is another > kind of hangup: > > debugger invoked on a UNBOUND-VARIABLE in thread #<THREAD "Hunchentoot > listener (*:8000)" RUNNING {AD467D1}>: > The variable HUNCHENTOOT:*ACCEPTOR* is unbound. > > I am trying this out with the hunchentoot default page by the way. > > /Peter > > Hans Hübner wrote: >>>> Peter, >>>> >>>> sorry, I am not able to reproduce the problem myself, so I made the >>>> patch blindly and made a mistake, working on the Lispworks code rather >>>> than the portable code that affects you. Please look at the first >>>> hunk of this diff: >>>> >>>> http://bknr.net/trac/changeset/4430?format=diff&new=4430 >>>> >>>> and let me know if that does it for you. >>>> >>>> Sorry, >>>> Hans >>>> >>>> On Mon, Jul 6, 2009 at 11:09, Peter >>>> Stiernströmpeter.stiernstrom@blixtvik.se wrote: >>>> Hi Hans, >>>> >>>> Hans Hübner wrote: >>>>>>> Hi Peter, >>>>>>> >>>>>>> 2009/7/6 Peter Stiernström peter.stiernstrom@blixtvik.se >>>>>>>> I had a quick peek at client-as-string and it does indeed not handle the >>>>>>>> sb-bsd-sockets:not-connected-error and if I put a handler-case around >>>>>>>> body of client-as-string returning nil when the exception appears I can >>>>>>>> not reproduce my problem anymore. >>>>>>>> >>>>>>>> This wouldn't provide a portable solution though :-P >>>>>>> This really is a bug that requires fixing in usocket. There are >>>>>>> multiple issues: >>>>>>> >>>>>>> - As shown in the backtrace, the problem is that the getpeername() >>>>>>> call fails for a socket that is not connected anymore. SBCL does the >>>>>>> right thing by signalling a condition. Other implementations (I >>>>>>> checked CCL) seem to behave differently, i.e. return NIL in such a >>>>>>> case. >>>>>>> >>>>>>> - Usocket does not unify the behavior, so the implementation specific >>>>>>> condition percolates to the caller, Hunchentoot in this case. >>>>>>> >>>>>>> - Hunchentoot is not prepared to handle conditions when creating a new >>>>>>> worker thread. The call to CLIENT-AS-STRING is made when creating the >>>>>>> name for the handler process of a new incoming connection, and that is >>>>>>> done in the context of the server thread. Therefore, the signalled >>>>>>> condition will stop the acceptor process. >>>>>>> >>>>>>> I spent some thoughts on how a "portable solution" would look like, >>>>>>> but given that the Lisp implementations vary greatly in behavior, >>>>>>> fixing usocket would be a pretty large task that I don't have the time >>>>>>> to do right now. Thus, I would propose this patch: >>>>>>> >>>>>>> http://bknr.net/trac/changeset/4428?format=diff&new=4428 >>>>>>> >>>>>>> It handles all conditions that are signaled during worker process >>>>>>> creation, under the theory that we want to prevent the acceptor >>>>>>> process from crashing under all circumstances. This is not a clean >>>>>>> solution in that it may paper over bugs, but given the limited number >>>>>>> of function invocations that are surrounded by a HANDLER-CASE, I'd say >>>>>>> that this is a proper intermediate fix. >>>>>>> >>>>>>> Please give it a try and let me know if it solves the problem for you. >>>> I tried your suggested patch but I can't seem to be able to get it to >>>> catch the exception for me. Were you able to duplicate the error >>>> yourself to verify that the suggested patch does indeed work? Since I am >>>> using the 1.0.0 hunchentoot release I couldn't just apply your patch but >>>> added the handler-case by hand and thus ended up with this in >>>> taskmaster.lisp: >>>> >>>> (defmethod handle-incoming-connection ((taskmaster >>>> one-thread-per-connection-taskmaster) handle) >>>> (incf *worker-counter*) >>>> ;; check if we need to perform a global GC >>>> (when (and *cleanup-interval* >>>> (zerop (mod *worker-counter* *cleanup-interval*))) >>>> (when *cleanup-function* >>>> (funcall *cleanup-function*))) >>>> (handler-case >>>> (mp:process-run-function (format nil "Hunchentoot worker (client: >>>> ~{~A:~A~})" >>>> (multiple-value-list >>>> (get-peer-address-and-port handle))) >>>> nil #'process-connection >>>> (taskmaster-acceptor taskmaster) handle) >>>> (error (cond) >>>> (log-message *lisp-errors-log-level* >>>> "Error while creating worker thread for new incoming >>>> connection: ~A" cond)))) >>>> >>>> /Peter >>>> >>>> >>>>>>> -Hans >>>>>>> >>>>>>> _______________________________________________ >>>>>>> tbnl-devel site list >>>>>>> tbnl-devel@common-lisp.net >>>>>>> http://common-lisp.net/mailman/listinfo/tbnl-devel > _______________________________________________ > tbnl-devel site list > tbnl-devel@common-lisp.net > http://common-lisp.net/mailman/listinfo/tbnl-devel >>>> _______________________________________________ >>>> tbnl-devel site list >>>> tbnl-devel@common-lisp.net >>>> http://common-lisp.net/mailman/listinfo/tbnl-devel

---

tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

...

...

> _______________________________________________ > tbnl-devel site list > tbnl-devel@common-lisp.net > http://common-lisp.net/mailman/listinfo/tbnl-devel

---

tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

...

...

...

---

tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

_______________________________________________ tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

...

---

tbnl-devel site list tbnl-devel@common-lisp.net http://common-lisp.net/mailman/listinfo/tbnl-devel

- -- Med vänlig hälsning,

Peter Stiernström 0708-810932 Blixtvik AB