Catch errors while processing a request

[mhkoji]

If clack with hunchentoot is launched and errors while processing requests occur many times, the server always returns a 503 response only, which does'nt seems to be an expected behaviour. This PR fixes this issue.

The following is an example for reproducing the issue:

Server:

$ for i in {1..10000};do echo "foo" >> /tmp/foo; done
$ ros -s lack-middleware-static -s clack -e '(clack:clackup (lack.app.file:make-app :file "/tmp/foo") :use-thread nil)'

Client:

CL-USER> (ql:quickload '(:usocket :bordeaux-threads))
CL-USER> (mapcar #'bt:join-thread
                 (loop repeat 300 collect (bt:make-thread
                                           (lambda () ;; the broken pipe error occurs
                                             (usocket:with-client-socket (a b "localhost" 5000)
                                               (write-sequence (format nil "GET / HTTP/1.1~A~A~A~A" #\Return #\Linefeed #\Return #\Linefeed) b)
                                               (force-output b))))))

The issue is because the current hunchentoot handler doesn't catch errors while processing a request, but invoke the debugger, which makes the thread stop. The thread is alive with the debugger being invoked. Many errors cause many threads and the server can't create anther thread for a new request.

hunchentoot:*catch-errors-p* is the variable whose value decides whether the debugger is invoked or not. The nil value invokes the debugger. While the clack.handler.hunchentoot::initialize method sets the variable to T, clack.handler.hunchentoot::acceptor-dispatch-request rebinds the variable to nil, which seems to be the root cause.

[fukamachi]

I'm not sure I could get what you mean, but at the first look, :debug nil option of clackup may work for it.

[mhkoji]

:debug nil option of clackup may work for it.

Unfortunately, :debug nil could not solve the problem. Clack showed logs as follows

$ ros -s lack-middleware-static -s clack -e '(clack:clackup (lack.app.file:make-app :file "/tmp/foo") :use-thread nil :debug nil :port 2222)'
Hunchentoot server is going to start.
Listening on 127.0.0.1:2222.
Couldn't write to #<SB-SYS:FD-STREAM for "socket 127.0.0.1:2222, peer: 127.0.0.1:43386" {10031E7D73}>:
  Broken pipeCouldn't write to #<SB-SYS:FD-STREAM for "socket 127.0.0.1:2222, peer: 127.0.0.1:43388" {1003617933}>:
               Broken pipe

debugger invoked on a TYPE-ERROR in thread
#<THREAD "hunchentoot-worker-127.0.0.1:43388" RUNNING {100361EA33}>:
  The value
    NIL
  is not of type
    STREAM
  when binding STREAM

The current thread is not at the foreground,
SB-THREAD:RELEASE-FOREGROUND has to be called in #<SB-THREAD:THREAD "main thread" RUNNING {1001580103}>
for this thread to enter the debugger.

...

SB-THREAD:RELEASE-FOREGROUND has to be called in 3394" {100362F563}>:
Couldn't write to #<SB-SYS:FD-STREAM for "socket 127.0.0.1:2222, peer: 127.0.0.1:43378" {1002EC75A3}>:
Couldn't write to #<SB-SYS:FD-STREAM for "socket 127.0.0.1:2222, peer: 127.0.0.1:43422" {1003CAD0E3}>:
Couldn't write to #<SB-SYS:FD-STREAM for "socket 127.0.0.1:2222, peer: 127.0.0.1:43366" {1002C16E73}>:

...

[2021-02-08 08:41:04 [WARNING]] Can't handle a new request, too many request threads already
[2021-02-08 08:41:04 [WARNING]] Can't handle a new request, too many request threads already
[2021-02-08 08:41:04 [WARNING]] Can't handle a new request, too many request threads already
[2021-02-08 08:41:04 [WARNING]] Can't handle a new request, too many request threads already
[2021-02-08 08:41:04 [WARNING]] Can't handle a new request, too many request threads already
[2021-02-08 08:41:04 [WARNING]] Can't handle a new request, too many request threads already
[2021-02-08 08:41:04 [WARNING]] Can't handle a new request, too many request threads already
[2021-02-08 08:41:04 [WARNING]] Can't handle a new request, too many request threads already
[2021-02-08 08:41:04 [WARNING]] Can't handle a new request, too many request threads already
[2021-02-08 08:41:04 [WARNING]] Can't handle a new request, too many request threads already
[2021-02-08 08:41:04 [WARNING]] Can't handle a new request, too many request threads already
[2021-02-08 08:41:04 [WARNING]] Can't handle a new request, too many request threads already
[2021-02-08 08:41:04 [WARNING]] Can't handle a new request, too many request threads already