Hi.
For my development I've tried to setup hunchentoot error logging/condition handling that better suits taste. Here's my setup (code snippets to reduce word clutter):
(setf hunchentoot:*catch-errors-p* nil hunchentoot::*log-lisp-backtraces-p* t hunchentoot::*log-lisp-errors-p* t hunchentoot::*log-lisp-warnings-p* t hunchentoot::*show-lisp-errors-p* t hunchentoot::*show-lisp-backtraces-p* t)
(defgeneric maybe-log-condition (condition) (:documentation "This generic function is called whenever a condition CONDITION is about to be logged in an application. You might want to specialize it on specific condition classes to fine-tune error and warning logging in addition to Hunchentoot's *log-lisp-errors-p* and *log-lisp-warnings-p*.") (:method (condition) t))
(defmethod log-message :around (log-level fmt &rest args) (let ((*log-level* log-level) (*fmt* fmt) (condition (and args (car args)))) (declare (special *log-level* *fmt*)) (cond ((and condition (typep condition 'condition)) (when (maybe-log-condition condition) (call-next-method))) (t (call-next-method)))))
(defmethod maybe-invoke-debugger ((condition sb-int:simple-stream-error)) ; muffle useless condition reporting (cond ((eql (search "/img/" (script-name *request*)) 0) (log-message :warn "ignored condition for ~a: ~a" (script-name *request*) condition)) (t (call-next-method))))
(defmethod maybe-log-condition ((condition sb-int:simple-stream-error)) nil)
It's rather crude workaround for something that should probably be more tightly integrated into hunchentoot (customizable error/warning logging similar to maybe-invoke-debugger). Notice maybe-invoke-debugger specialized for sb-int:simple-stream-error. I've put that in my development setup because I've tried to silence Firefox related errors, which has nasty habit of dropping connection on favicon.ico retrieval (well, that's what I suspect; haven't check that theory with packet sniffer) that results in "Broken pipe" condition.
So far all fine and dandy. But, for every such condition handled by my code hunchentoot logs following line:
[2008-05-10 11:41:42 [ERROR]] Error while processing connection: The variable *REQUEST* is unbound.
No more information available. So I've modified hunchentoot a little bit:
diff -x '*.fasl' -r -u -w -B hunchentoot-0.15.6.orig/server.lisp hunchentoot-0.15.6/server.lisp --- hunchentoot-0.15.6.orig/server.lisp 2008-04-09 10:17:48.000000000 +0200 +++ hunchentoot-0.15.6/server.lisp 2008-04-21 22:25:33.000000000 +0200 @@ -282,6 +282,7 @@ (lambda (cond) (log-message *lisp-errors-log-level* "Error while processing connection: ~A" cond) + (log-message *lisp-errors-log-level* "~a" (get-backtrace cond)) (return-from process-connection))) (warning ;; log all warnings which aren't caught inside
and got following:
[2008-05-10 11:41:42 [ERROR]] Error while processing connection: The variable *REQUEST* is unbound. [2008-05-10 11:41:43 [ERROR]] 0: (SB-DEBUG::MAP-BACKTRACE #<CLOSURE (LAMBDA #) {AF6C86D}>)[:EXTERNAL] 1: (SB-DEBUG:BACKTRACE 536870911 #<SB-IMPL::STRING-OUTPUT-STREAM {AF6C809}>) 2: (GET-BACKTRACE #<unused argument>) 3: ((LAMBDA (COND)) #<UNBOUND-VARIABLE *REQUEST* {A793961}>) 4: ((LAMBDA (COND)) #<UNBOUND-VARIABLE *REQUEST* {A793961}>)[:EXTERNAL] 5: (SIGNAL #<UNBOUND-VARIABLE *REQUEST* {A793961}>)[:EXTERNAL] 6: (ERROR UNBOUND-VARIABLE)[:EXTERNAL] 7: (SB-KERNEL::UNBOUND-SYMBOL-ERROR-HANDLER #<unavailable argument> #.(SB-SYS:INT-SAP #XB51C1DF0) #<SB-ALIEN-INTERNALS:ALIEN-VALUE :SAP #XB51C1A7C :TYPE (* (SB-ALIEN:STRUCT
SB-VM::OS-CONTEXT-T-STRUCT))> (14)) 8: (SB-KERNEL::UNBOUND-SYMBOL-ERROR-HANDLER #<unavailable argument> #.(SB-SYS:INT-SAP #XB51C1DF0) #<SB-ALIEN-INTERNALS:ALIEN-VALUE :SAP #XB51C1A7C :TYPE (* (SB-ALIEN:STRUCT
SB-VM::OS-CONTEXT-T-STRUCT))> (14))[:EXTERNAL] 9: (SB-KERNEL:INTERNAL-ERROR #.(SB-SYS:INT-SAP #XB51C1A7C) #<unavailable argument>) 10: ("foreign function: call_into_lisp") 11: ("foreign function: funcall2") 12: ("foreign function: interrupt_internal_error") 13: ("foreign function: handle_trap") 14: ((SB-PCL::FAST-METHOD MAYBE-INVOKE-DEBUGGER (SB-INT:SIMPLE-STREAM-ERROR)) #<unused argument> #S(SB-PCL::FAST-METHOD-CALL :FUNCTION #<FUNCTION #> :PV NIL :NEXT-METHOD-CALL NIL :ARG-INFO (1)) #<SB-INT:SIMPLE-STREAM-ERROR {A78E219}>) 15: (SIGNAL #<SB-INT:SIMPLE-STREAM-ERROR {A78E219}>)[:EXTERNAL] 16: (ERROR SB-INT:SIMPLE-STREAM-ERROR)[:EXTERNAL] 17: (SB-IMPL::SIMPLE-STREAM-PERROR "Couldn't write to ~s" #<SB-SYS:FD-STREAM for "a socket" {B123609}> 32) 18: (SB-IMPL::SIMPLE-STREAM-PERROR "Couldn't write to ~s" #<SB-SYS:FD-STREAM for "a socket" {B123609}> 32)[:EXTERNAL] 19: (FORCE-OUTPUT #<SB-SYS:FD-STREAM for "a socket" {B123609}>) 20: ((SB-PCL::FAST-METHOD SB-GRAY:STREAM-FORCE-OUTPUT (CHUNGA:CHUNKED-OUTPUT-STREAM)) #<unused argument> #<unused argument> #<CHUNGA:CHUNKED-IO-STREAM {B127C49}>) 21: (FORCE-OUTPUT #<CHUNGA:CHUNKED-IO-STREAM {B127C49}>) 22: (FORCE-OUTPUT #<FLEXI-STREAMS::FLEXI-UTF-8-IO-STREAM {B12A4E9}>) 23: (HUNCHENTOOT::PROCESS-CONNECTION #<HUNCHENTOOT::SERVER {B3C6FB1}> #<SB-BSD-SOCKETS:INET-SOCKET descriptor 11 {B121819}>) 24: ((LAMBDA ())) 25: ((FLET SB-THREAD::WITH-MUTEX-THUNK)) 26: ((FLET #:WITHOUT-INTERRUPTS-BODY-[CALL-WITH-MUTEX]438)) 27: (SB-THREAD::CALL-WITH-MUTEX #<CLOSURE (FLET SB-THREAD::WITH-MUTEX-THUNK) {B51C2295}> #S(SB-THREAD:MUTEX :NAME "thread result lock" :%OWNER #<SB-THREAD:THREAD "hunchentoot-worker-2" {B1225D9}> :STATE 1) #<SB-THREAD:THREAD "hunchentoot-worker-2" {B1225D9}> T) 28: ((LAMBDA ())) 29: ("foreign function: call_into_lisp") 30: ("foreign function: funcall0") 31: ("foreign function: new_thread_trampoline") 32: ("foreign function: #xB7FD2240")
Looking at the above backtrace and process-connection source code I wasn't able to figure out anything constructive. I'm stuck. It looks for me like double error (error during error handling), but what do I know? Can someone tell me what am I doing wrong? Can I avoid this "The variable *REQUEST* is unbound." error? Is this hunchentoot error or my silly mistake? Take into account that these are my first 40 or so hours with CL (not even mentioning Hunchentoot).
I'm using SBCL 1.0.15 and Hunchentoot 0.15.6.
Thanks
Tomasz
On Sat, 10 May 2008 22:53:34 +0200, "Tomasz Skutnik" tomasz.skutnik@gmail.com wrote:
Can someone tell me what am I doing wrong?
In your method you're trying to unconditionally access the *REQUEST* variable which is only guaranteed to be bound to the current request object while a handler is executed. In fact, the errors you're trying to deal with happen before a request object is created.
Edi.
In your method you're trying to unconditionally access the *REQUEST* variable which is only guaranteed to be bound to the current request object while a handler is executed. In fact, the errors you're trying to deal with happen before a request object is created.
Edi.
Thanks Edi. You mean maybe-invoke-debugger? I've modified to look like this:
(defmethod maybe-invoke-debugger ((condition sb-int:simple-stream-error)) ; muffle useless condition reporting (cond ((boundp '*request*) (cond ((eql (search "/img/" (script-name *request*)) 0) (log-message :warn "ignored condition for ~a: ~a" (script-name *request*) condition)) (t (call-next-method)))) (t nil)))
That's probably what I meant (sorry for algolesque):
- if *request* is bound (we're in handler): - if we're serving '/img/" -> ignore & log condition - otherwise -> call next method (i.e. invoke debugger) - otherwise (we're somewhere in hunchentoot internals) -> ignore condition
Looks like that solves my problem - condition logged without backtrace, debugger silenced.
Thanks again.
Tomasz