lack/caveman2 crashes on sbcl/linux

[slyrus]

I can semi-reliably trigger a crash on SBCL (latest head) running on 64-bit linux by editing my CSS file and then reloading my web page. A representative stack trace is attached:

Callback Error: the message-complete callback failed Unhandled memory fault at #xD. [Condition of type FAST-HTTP.ERROR:CB-MESSAGE-COMPLETE]

Restarts: 0: [SKIP-PRINTING-FRAME] Skip printing frame 2 1: [ABORT] abort thread (#<THREAD "clack-handler-woo" RUNNING {1001DB4B23}>)

Backtrace: 0: ((FLET "H0" :IN FAST-HTTP.PARSER::PARSE-BODY) #) 1: (SB-KERNEL::%SIGNAL #<SB-SYS:MEMORY-FAULT-ERROR {1004C78C53}>) 2: (ERROR SB-SYS:MEMORY-FAULT-ERROR :ADDRESS 13) 3: (SB-SYS:MEMORY-FAULT-ERROR) 4: ("foreign function: call_into_lisp") 5: ("foreign function: post_signal_tramp") 6: [error printing frame] 7: ((LABELS SB-IMPL::HANDLE-IT :IN SB-KERNEL:OUTPUT-OBJECT) #<SB-PRETTY:PRETTY-STREAM {1004C78B13}>) 8: [error printing frame] 9: ((FLET "PPRINT-BLOCK" :IN SB-DEBUG::PRINT-FRAME-CALL) # #<SB-PRETTY:PRETTY-STREAM {1004C78B13}>) 10: ((FLET "WITH-PRETTY-STREAM0" :IN SB-PRETTY::CALL-LOGICAL-BLOCK-PRINTER) #<SB-PRETTY:PRETTY-STREAM {1004C78B13}>) 11: (SB-PRETTY::CALL-LOGICAL-BLOCK-PRINTER #<CLOSURE (FLET "PPRINT-BLOCK" :IN SB-DEBUG::PRINT-FRAME-CALL) {7F99F395CECB}> #<SB-IMPL::STRING-OUTPUT-STREAM {1004C69B63}> "(" NIL ")" NIL) 12: (SB-DEBUG::PRINT-FRAME-CALL #<SB-DI::COMPILED-FRAME DJULA:RENDER-TEMPLATE> #<SB-IMPL::STRING-OUTPUT-STREAM {1004C69B63}> :PRINT-FRAME-SOURCE NIL :NUMBER 2 :METHOD-FRAME-STYLE :NORMAL :EMERGENCY-BEST-.. 13: ((LAMBDA (SB-DEBUG::FRAME) :IN PRINT-BACKTRACE) #<SB-DI::COMPILED-FRAME DJULA:RENDER-TEMPLATE>) 14: (SB-DEBUG::MAP-BACKTRACE #<CLOSURE (LAMBDA (SB-DEBUG::FRAME) :IN PRINT-BACKTRACE) {1004C6D01B}> :START 0 :FROM # :COUNT 4611686018427.. 15: ((FLET "THUNK4" :IN PRINT-BACKTRACE)) 16: ((LAMBDA NIL :IN SB-DEBUG::FUNCALL-WITH-DEBUG-IO-SYNTAX)) 17: (SB-IMPL::CALL-WITH-SANE-IO-SYNTAX #<CLOSURE (LAMBDA NIL :IN SB-DEBUG::FUNCALL-WITH-DEBUG-IO-SYNTAX) {1004C6C18B}>) 18: (SB-IMPL::%WITH-STANDARD-IO-SYNTAX #<CLOSURE (FLET "THUNK" :IN SB-DEBUG::FUNCALL-WITH-DEBUG-IO-SYNTAX) {7F99F395D41B}>) 19: (SB-DEBUG::FUNCALL-WITH-DEBUG-IO-SYNTAX #<CLOSURE (FLET "THUNK4" :IN PRINT-BACKTRACE) {7F99F395D4CB}>) 20: (PRINT-BACKTRACE :STREAM #<SB-IMPL::STRING-OUTPUT-STREAM {1004C69B63}> :START 0 :FROM :DEBUGGER-FRAME :COUNT 4611686018427387903 :PRINT-THREAD T :PRINT-FRAME-SOURCE NIL :METHOD-FRAME-STYLE NIL :EMERGE.. 21: (TRIVIAL-BACKTRACE:PRINT-BACKTRACE-TO-STREAM #<SB-IMPL::STRING-OUTPUT-STREAM {1004C69B63}>) 22: (TRIVIAL-BACKTRACE:PRINT-BACKTRACE #<SB-SYS:MEMORY-FAULT-ERROR {1004C699F3}> :OUTPUT NIL :IF-EXISTS :APPEND :VERBOSE NIL) 23: [error printing frame] 24: ((LABELS MYWAY.MAPPER::DISPATCH-WITH-RULES :IN MYWAY.MAPPER:DISPATCH) (#<NINGLE.ROUTE:NINGLE-ROUTE {10055A8683}> #<NINGLE.ROUTE:NINGLE-ROUTE {10055A8693}> #<NINGLE.ROUTE:NINGLE-ROUTE {10055A86A3}> #<N.. 25: ((:METHOD LACK.COMPONENT:CALL (NINGLE.APP: T)) #<TUMAK.WEB:: {10029C4F83}> #) [fast-method] 26: ((:METHOD LACK.COMPONENT:CALL (CAVEMAN2.APP: T)) #<TUMAK.WEB:: {10029C4F83}> (:LACK.SESSION.OPTIONS (:ID "0fc83f763b9b52531ac6923c277f91eb6759ee54" :NEW-SESSION NIL :CHANGE-ID NIL ...) :LACK.. 27: ((:METHOD LACK.COMPONENT:CALL :AROUND (NINGLE.APP: T)) #<TUMAK.WEB:: {10029C4F83}> (:LACK.SESSION.OPTIONS (:ID "0fc83f763b9b52531ac6923c277f91eb6759ee54" :NEW-SESSION NIL :CHANGE-ID NIL ...).. 28: ((LAMBDA (TUMAK.APP::ENV) :IN "/src/lisp/tumak/app.lisp") (:LACK.SESSION.OPTIONS (:ID "0fc83f763b9b52531ac6923c277f91eb6759ee54" :NEW-SESSION NIL :CHANGE-ID NIL ...) :LACK.SESSION #<HASH-TABLE :TEST E.. 29: ((LAMBDA (LACK.MIDDLEWARE.SESSION::ENV) :IN "/root/quicklisp/host-local-projects/lack/src/middleware/session.lisp") (:LACK.SESSION.OPTIONS (:ID "0fc83f763b9b52531ac6923c277f91eb6759ee54" :NEW-SESSION .. 30: (LACK.UTIL:FUNCALL-WITH-CB #<CLOSURE (LAMBDA (LACK.MIDDLEWARE.SESSION::ENV) :IN "/root/quicklisp/host-local-projects/lack/src/middleware/session.lisp") {10029C5AFB}> (:RAW-BODY #<FLEXI-STREAMS::VECTOR.. 31: ((LAMBDA (LACK.MIDDLEWARE.BACKTRACE::ENV) :IN "/root/quicklisp/host-local-projects/lack/src/middleware/backtrace.lisp") (:RAW-BODY #<FLEXI-STREAMS::VECTOR-INPUT-STREAM {1008E43373}> :REQUEST-METHOD :G.. 32: ((LAMBDA NIL :IN WOO::SETUP-PARSER)) 33: ((LAMBDA (FAST-HTTP.HTTP:HTTP) :IN FAST-HTTP:MAKE-PARSER) #) 34: (FAST-HTTP.PARSER::PARSE-BODY #S(FAST-HTTP.HTTP:HTTP-REQUEST :METHOD :GET :MAJOR-VERSION 1 :MINOR-VERSION 1 :STATUS 0 :CONTENT-LENGTH NIL :CHUNKED-P NIL ...) # #<unavailable argu.. 35: (FAST-HTTP.PARSER:PARSE-REQUEST #S(FAST-HTTP.HTTP:HTTP-REQUEST :METHOD :GET :MAJOR-VERSION 1 :MINOR-VERSION 1 :STATUS 0 :CONTENT-LENGTH NIL :CHUNKED-P NIL ...) #S(FAST-HTTP.PARSER:CALLBACKS :MESSAGE-B.. 36: ((LAMBDA (FAST-HTTP::DATA &KEY :START :END) :IN FAST-HTTP:MAKE-PARSER) #(71 69 84 32 47 98 ...) :START # :END #) 37: (WOO::READ-CB #S(WOO.EV.SOCKET:SOCKET :WATCHERS #(#.(SB-SYS:INT-SAP #X7F99EC0115B0) #.(SB-SYS:INT-SAP #X7F99EC0115F0) #.(SB-SYS:INT-SAP #X7F99EC011630)) :LAST-ACTIVITY 1.503896933140369d9 :FD 15 :REMO.. 38: ((LAMBDA (WOO.EV.TCP::EVLOOP WOO.EV.TCP::WATCHER WOO.EV.TCP::EVENTS) :IN "/root/quicklisp/host-local-projects/woo/src/ev/tcp.lisp") # #.(SB-SYS:INT-SAP #X7F99EC0115B0) #<unused argume.. 39: ((LAMBDA (SB-ALIEN::ARGS-POINTER SB-ALIEN::RESULT-POINTER FUNCTION) :IN "/root/quicklisp/host-local-projects/woo/src/ev/socket.lisp") 70149596705408 70149596705404 #<FUNCTION (LAMBDA (WOO.EV.TCP::EVLO.. 40: ("foreign function: call_into_lisp") 41: ("foreign function: funcall3") 42: ("foreign function: callback_wrapper_trampoline") 43: ("foreign function: #x2010067C") 44: (WOO:RUN #<CLOSURE (LAMBDA (LACK.MIDDLEWARE.BACKTRACE::ENV) :IN "/root/quicklisp/host-local-projects/lack/src/middleware/backtrace.lisp") {10019D64BB}> :DEBUG T :PORT 8080 :ADDRESS "0.0.0.0" :LISTEN N.. 45: ((LAMBDA NIL :IN BORDEAUX-THREADS::BINDING-DEFAULT-SPECIALS)) 46: ((FLET "WITHOUT-INTERRUPTS-BODY-4" :IN SB-THREAD::INITIAL-THREAD-FUNCTION-TRAMPOLINE)) 47: ((FLET SB-THREAD::WITH-MUTEX-THUNK :IN SB-THREAD::INITIAL-THREAD-FUNCTION-TRAMPOLINE)) 48: ((FLET "WITHOUT-INTERRUPTS-BODY-1" :IN SB-THREAD::CALL-WITH-MUTEX)) 49: (SB-THREAD::CALL-WITH-MUTEX #<CLOSURE (FLET SB-THREAD::WITH-MUTEX-THUNK :IN SB-THREAD::INITIAL-THREAD-FUNCTION-TRAMPOLINE) {7F99F395ED6B}> #<SB-THREAD:MUTEX "thread result lock" owner: #<SB-THREAD:THR.. 50: (SB-THREAD::INITIAL-THREAD-FUNCTION-TRAMPOLINE #<SB-THREAD:THREAD "clack-handler-woo" RUNNING {1001DB4B23}> NIL #<CLOSURE (LAMBDA NIL :IN BORDEAUX-THREADS::BINDING-DEFAULT-SPECIALS) {1001DB4ACB}> (#<S.. 51: ("foreign function: call_into_lisp") 52: ("foreign function: new_thread_trampoline") Callback Error: the message-complete callback failed Unhandled memory fault at #xD. [Condition of type FAST-HTTP.ERROR:CB-MESSAGE-COMPLETE]

Restarts: 0: [SKIP-PRINTING-FRAME] Skip printing frame 2 1: [ABORT] abort thread (#<THREAD "clack-handler-woo" RUNNING {1001DB4B23}>)

Backtrace: 0: ((FLET "H0" :IN FAST-HTTP.PARSER::PARSE-BODY) #) 1: (SB-KERNEL::%SIGNAL #<SB-SYS:MEMORY-FAULT-ERROR {1004C78C53}>) 2: (ERROR SB-SYS:MEMORY-FAULT-ERROR :ADDRESS 13) 3: (SB-SYS:MEMORY-FAULT-ERROR) 4: ("foreign function: call_into_lisp") 5: ("foreign function: post_signal_tramp") 6: [error printing frame] 7: ((LABELS SB-IMPL::HANDLE-IT :IN SB-KERNEL:OUTPUT-OBJECT) #<SB-PRETTY:PRETTY-STREAM {1004C78B13}>) 8: [error printing frame] 9: ((FLET "PPRINT-BLOCK" :IN SB-DEBUG::PRINT-FRAME-CALL) # #<SB-PRETTY:PRETTY-STREAM {1004C78B13}>) 10: ((FLET "WITH-PRETTY-STREAM0" :IN SB-PRETTY::CALL-LOGICAL-BLOCK-PRINTER) #<SB-PRETTY:PRETTY-STREAM {1004C78B13}>) 11: (SB-PRETTY::CALL-LOGICAL-BLOCK-PRINTER #<CLOSURE (FLET "PPRINT-BLOCK" :IN SB-DEBUG::PRINT-FRAME-CALL) {7F99F395CECB}> #<SB-IMPL::STRING-OUTPUT-STREAM {1004C69B63}> "(" NIL ")" NIL) 12: (SB-DEBUG::PRINT-FRAME-CALL #<SB-DI::COMPILED-FRAME DJULA:RENDER-TEMPLATE> #<SB-IMPL::STRING-OUTPUT-STREAM {1004C69B63}> :PRINT-FRAME-SOURCE NIL :NUMBER 2 :METHOD-FRAME-STYLE :NORMAL :EMERGENCY-BEST-.. 13: ((LAMBDA (SB-DEBUG::FRAME) :IN PRINT-BACKTRACE) #<SB-DI::COMPILED-FRAME DJULA:RENDER-TEMPLATE>) 14: (SB-DEBUG::MAP-BACKTRACE #<CLOSURE (LAMBDA (SB-DEBUG::FRAME) :IN PRINT-BACKTRACE) {1004C6D01B}> :START 0 :FROM # :COUNT 4611686018427.. 15: ((FLET "THUNK4" :IN PRINT-BACKTRACE)) 16: ((LAMBDA NIL :IN SB-DEBUG::FUNCALL-WITH-DEBUG-IO-SYNTAX)) 17: (SB-IMPL::CALL-WITH-SANE-IO-SYNTAX #<CLOSURE (LAMBDA NIL :IN SB-DEBUG::FUNCALL-WITH-DEBUG-IO-SYNTAX) {1004C6C18B}>) 18: (SB-IMPL::%WITH-STANDARD-IO-SYNTAX #<CLOSURE (FLET "THUNK" :IN SB-DEBUG::FUNCALL-WITH-DEBUG-IO-SYNTAX) {7F99F395D41B}>) 19: (SB-DEBUG::FUNCALL-WITH-DEBUG-IO-SYNTAX #<CLOSURE (FLET "THUNK4" :IN PRINT-BACKTRACE) {7F99F395D4CB}>) 20: (PRINT-BACKTRACE :STREAM #<SB-IMPL::STRING-OUTPUT-STREAM {1004C69B63}> :START 0 :FROM :DEBUGGER-FRAME :COUNT 4611686018427387903 :PRINT-THREAD T :PRINT-FRAME-SOURCE NIL :METHOD-FRAME-STYLE NIL :EMERGE.. 21: (TRIVIAL-BACKTRACE:PRINT-BACKTRACE-TO-STREAM #<SB-IMPL::STRING-OUTPUT-STREAM {1004C69B63}>) 22: (TRIVIAL-BACKTRACE:PRINT-BACKTRACE #<SB-SYS:MEMORY-FAULT-ERROR {1004C699F3}> :OUTPUT NIL :IF-EXISTS :APPEND :VERBOSE NIL) 23: [error printing frame] 24: ((LABELS MYWAY.MAPPER::DISPATCH-WITH-RULES :IN MYWAY.MAPPER:DISPATCH) (#<NINGLE.ROUTE:NINGLE-ROUTE {10055A8683}> #<NINGLE.ROUTE:NINGLE-ROUTE {10055A8693}> #<NINGLE.ROUTE:NINGLE-ROUTE {10055A86A3}> #<N.. 25: ((:METHOD LACK.COMPONENT:CALL (NINGLE.APP: T)) #<TUMAK.WEB:: {10029C4F83}> #) [fast-method] 26: ((:METHOD LACK.COMPONENT:CALL (CAVEMAN2.APP: T)) #<TUMAK.WEB:: {10029C4F83}> (:LACK.SESSION.OPTIONS (:ID "0fc83f763b9b52531ac6923c277f91eb6759ee54" :NEW-SESSION NIL :CHANGE-ID NIL ...) :LACK.. 27: ((:METHOD LACK.COMPONENT:CALL :AROUND (NINGLE.APP: T)) #<TUMAK.WEB:: {10029C4F83}> (:LACK.SESSION.OPTIONS (:ID "0fc83f763b9b52531ac6923c277f91eb6759ee54" :NEW-SESSION NIL :CHANGE-ID NIL ...).. 28: ((LAMBDA (TUMAK.APP::ENV) :IN "/src/lisp/tumak/app.lisp") (:LACK.SESSION.OPTIONS (:ID "0fc83f763b9b52531ac6923c277f91eb6759ee54" :NEW-SESSION NIL :CHANGE-ID NIL ...) :LACK.SESSION #<HASH-TABLE :TEST E.. 29: ((LAMBDA (LACK.MIDDLEWARE.SESSION::ENV) :IN "/root/quicklisp/host-local-projects/lack/src/middleware/session.lisp") (:LACK.SESSION.OPTIONS (:ID "0fc83f763b9b52531ac6923c277f91eb6759ee54" :NEW-SESSION .. 30: (LACK.UTIL:FUNCALL-WITH-CB #<CLOSURE (LAMBDA (LACK.MIDDLEWARE.SESSION::ENV) :IN "/root/quicklisp/host-local-projects/lack/src/middleware/session.lisp") {10029C5AFB}> (:RAW-BODY #<FLEXI-STREAMS::VECTOR.. 31: ((LAMBDA (LACK.MIDDLEWARE.BACKTRACE::ENV) :IN "/root/quicklisp/host-local-projects/lack/src/middleware/backtrace.lisp") (:RAW-BODY #<FLEXI-STREAMS::VECTOR-INPUT-STREAM {1008E43373}> :REQUEST-METHOD :G.. 32: ((LAMBDA NIL :IN WOO::SETUP-PARSER)) 33: ((LAMBDA (FAST-HTTP.HTTP:HTTP) :IN FAST-HTTP:MAKE-PARSER) #) 34: (FAST-HTTP.PARSER::PARSE-BODY #S(FAST-HTTP.HTTP:HTTP-REQUEST :METHOD :GET :MAJOR-VERSION 1 :MINOR-VERSION 1 :STATUS 0 :CONTENT-LENGTH NIL :CHUNKED-P NIL ...) # #<unavailable argu.. 35: (FAST-HTTP.PARSER:PARSE-REQUEST #S(FAST-HTTP.HTTP:HTTP-REQUEST :METHOD :GET :MAJOR-VERSION 1 :MINOR-VERSION 1 :STATUS 0 :CONTENT-LENGTH NIL :CHUNKED-P NIL ...) #S(FAST-HTTP.PARSER:CALLBACKS :MESSAGE-B.. 36: ((LAMBDA (FAST-HTTP::DATA &KEY :START :END) :IN FAST-HTTP:MAKE-PARSER) #(71 69 84 32 47 98 ...) :START # :END #) 37: (WOO::READ-CB #S(WOO.EV.SOCKET:SOCKET :WATCHERS #(#.(SB-SYS:INT-SAP #X7F99EC0115B0) #.(SB-SYS:INT-SAP #X7F99EC0115F0) #.(SB-SYS:INT-SAP #X7F99EC011630)) :LAST-ACTIVITY 1.503896933140369d9 :FD 15 :REMO.. 38: ((LAMBDA (WOO.EV.TCP::EVLOOP WOO.EV.TCP::WATCHER WOO.EV.TCP::EVENTS) :IN "/root/quicklisp/host-local-projects/woo/src/ev/tcp.lisp") # #.(SB-SYS:INT-SAP #X7F99EC0115B0) #<unused argume.. 39: ((LAMBDA (SB-ALIEN::ARGS-POINTER SB-ALIEN::RESULT-POINTER FUNCTION) :IN "/root/quicklisp/host-local-projects/woo/src/ev/socket.lisp") 70149596705408 70149596705404 #<FUNCTION (LAMBDA (WOO.EV.TCP::EVLO.. 40: ("foreign function: call_into_lisp") 41: ("foreign function: funcall3") 42: ("foreign function: callback_wrapper_trampoline") 43: ("foreign function: #x2010067C") 44: (WOO:RUN #<CLOSURE (LAMBDA (LACK.MIDDLEWARE.BACKTRACE::ENV) :IN "/root/quicklisp/host-local-projects/lack/src/middleware/backtrace.lisp") {10019D64BB}> :DEBUG T :PORT 8080 :ADDRESS "0.0.0.0" :LISTEN N.. 45: ((LAMBDA NIL :IN BORDEAUX-THREADS::BINDING-DEFAULT-SPECIALS)) 46: ((FLET "WITHOUT-INTERRUPTS-BODY-4" :IN SB-THREAD::INITIAL-THREAD-FUNCTION-TRAMPOLINE)) 47: ((FLET SB-THREAD::WITH-MUTEX-THUNK :IN SB-THREAD::INITIAL-THREAD-FUNCTION-TRAMPOLINE)) 48: ((FLET "WITHOUT-INTERRUPTS-BODY-1" :IN SB-THREAD::CALL-WITH-MUTEX)) 49: (SB-THREAD::CALL-WITH-MUTEX #<CLOSURE (FLET SB-THREAD::WITH-MUTEX-THUNK :IN SB-THREAD::INITIAL-THREAD-FUNCTION-TRAMPOLINE) {7F99F395ED6B}> #<SB-THREAD:MUTEX "thread result lock" owner: #<SB-THREAD:THR.. 50: (SB-THREAD::INITIAL-THREAD-FUNCTION-TRAMPOLINE #<SB-THREAD:THREAD "clack-handler-woo" RUNNING {1001DB4B23}> NIL #<CLOSURE (LAMBDA NIL :IN BORDEAUX-THREADS::BINDING-DEFAULT-SPECIALS) {1001DB4ACB}> (#<S.. 51: ("foreign function: call_into_lisp") 52: ("foreign function: new_thread_trampoline")

Interestingly, it's always an unhandled memory fault at #xD (well, for this batch of errors anyway. I've seen, others but it's almost always a low integer.

[knobo]

Do you load the source at runtime, or is it a pre-built image? Does it also crash with my suggested patch: https://github.com/fukamachi/woo/pull/70

[slyrus]

Some things are prebuilt in the image, some at runtime. I'll try your patch.

[slyrus]

No dice. And now I can reliably trigger out just by reloading my app's main page a few times, but it's still always a memory fault at #xD. Any suggestions on how to debug this?

[knobo]

I guess it's something wrong with djula. Could you try to re-evaluate this line:

(defparameter template-registry (make-hash-table :test 'equal))

in your src/view.lisp file

Then reload your app in the browser. I'm at least 30% sure it will fix it, because of a bug in djula.

[slyrus]

Ok, I fixed (or at least papered over) my problem. Turned out I had two versions of mito around was picking up a slightly outdated that didn't have the recent fixes for count-dao where it wasn't unlispifying the slot name. So, fixing that makes the problem go away, but there's still the underlying issue where we're getting a memory fault instead of properly throwing the error down in the route handling code (or properly handing the error thrown down there, depending on how you look at it).

[slyrus]

For a little more info on this, it only seems to happen when I'm connected via SLIME and the error occurs upon error handling in the mito sql stuff. With no bogus SQL, everything seems fine. With bogus SQL when starting from the REPL, things seem fine, but if I'm connected via SLIME and an error occurs deep down in the mito code, things blow up.

[slyrus]

I'm still seeing roughly the same error. There's clearly a crashing problem (Unhandled memory fault) when have my container start up SBCL via its init scripts. In that case, if/when my web application throws an error, I get an unhandled memory fault at #xD. If I start SBCL from a shell, I get proper error handling.

Interestingly, the editing/saving of my CSS file, and reloading a page, seems to trigger the same error. Perhaps there's something wrong with IO event handling?

[knobo]

How are your css files loaded and served?

[slyrus]

static files via caveman2/woo

[slyrus]

@fukamachi any ideas here? I'm happy to set up an instance that you can log into if that would help. thanks!

[slyrus]

Turns out this was a bug in SBCL that had been around since February or so. Funcallable instances weren't properly scavenged by the GC and could occasionally get corrupted. Commit d3d881825 fixes the problem. Sorry for the false alarm for lack/woo/etc...