joaotavora / snooze

Common Lisp RESTful web development
207 stars 22 forks source link

Heap exhausted #8

Closed vindarel closed 6 years ago

vindarel commented 6 years ago

Hello,

I have some simple code that can throw right away a heap exhausted error O_o

$ ./my-app
Hunchentoot server is started.
Listening on localhost:9005.
Heap exhausted during garbage collection: 32 bytes available, 80 requested.
 Gen StaPg UbSta LaSta LUbSt Boxed Unboxed LB   LUB  !move  Alloc  Waste   Trig    WP  GCs Mem-age
   0:     0     0     0     0     0     0     0     0     0        0     0 10737418    0   0  0,0000
   1:     0     0     0     0     0     0     0     0     0        0     0 10737418    0   0  0,0000
   2: 27373 27366     0     0 14426  1312     0     0     0 515026272 676512  2000000    0   0  1,1068
   3:     0     0     0     0     0     0     0     0     0        0     0  2000000    0   0  0,0000
   4:     0     0     0     0     0     0     0     0     0        0     0  2000000    0   0  0,0000
   5:     0     0     0     0     0     0     0     0     0        0     0  2000000    0   0  0,0000
   6:     0     0     0     0  3991  1009     0     0     0 163840000     0  2000000 3820   0  0,0000
   Total bytes allocated    = 1072429888
   Dynamic-space-size bytes = 1073741824
GC control variables:
   *GC-INHIBIT* = true
   *GC-PENDING* = true
   *STOP-FOR-GC-PENDING* = false
fatal error encountered in SBCL pid 5286(tid 140737295906560):
Heap exhausted, game over.

Welcome to LDB, a low-level debugger for the Lisp runtime environment.
ldb> 

I built an executable out of the following minimal web app.

It defines two routes, an index with a text input and a results page. I noticed the problem when I used the browser's back and forth button, but also right away, now it happened after I entered a search query in the input and validated. I already managed to see search results (or lack of, given the lack of template in this snippet).

(defpackage torrents-gui
  (:use :cl
        :spinneret
        :snooze)
  (:export
   :start-app
   :main))
(in-package :torrents-gui)

(defvar *server*)

(defvar *torrents* nil)
(setf *torrents*
  '(((:TITLE . "Title")
    …
)))
;;
;; routes
;;
(defroute torrents (:get :text/html &key query)
          (if query
              (print-results *torrents* query) ;; saw "heap exhausted" 
              ))

(defroute index (:get :text/*)
          (search-page)) ;; always ok so far

;; root url
(setf *home-resource* "index")

;; print errors in the browser.
(setf snooze:*catch-errors* :verbose)
(setf hunchentoot:*catch-errors-p* t)

;;
;; templates
;;
(defmacro with-page ((&key title) &body body)
   `(with-html-string
      (:doctype)
      (:html
       (:head
        (:meta :http-equiv "Content-Type" :content "text/html; charset=utf-8") ;; useless
        (:meta :charset "UTF-8")
        (:meta :charset "UTF-8")
        (:link :rel "stylesheet" :type "text/css" :href "https://cdnjs.cloudflare.com/ajax/libs/semantic-ui/1.11.8/semantic.min.css")
        (:title ,title))
       (:div :class "ui grid"
             (:div :class "four wide column")
             (:div :class "height wide column"
                   (:body ,@body))))))

(defun search-page ()
  (with-page (:title "cl-torrents")
    (:header
     (:h1 "index"))
    (:section
     (:div "Search")
     (:form :action "/torrents"
      (:div :class "ui input"
            (:input :placeholder "search..." :name "search" :type "text"))
      (:button :class "ui primary button" :type "submit" "search")))))

(defun print-results (res query)
  (if (and res query)
      (with-page (:title "Torrents debug"))
   ;; deleted
      ))

;;
;; app
;;
(defun start-app (&key (port *port*))
  (setf lparallel:*kernel* (lparallel:make-kernel 2))
  (handler-case
      (setq *server* (clack:clackup
                      (snooze:make-clack-app)
                      :port (find-port:find-port :min 9003)))
    ;; not helping ? Hunchentoot takes over.
    (error (c) (format t "Unexpected error: ~a~&Aborting.~&" c))))

(defun main ()
  (start-app)
  (handler-case (bt:join-thread (find-if (lambda (th)
                                           (search "hunchentoot" (bt:thread-name th)))
                                         (bt:all-threads)))
    (#+sbcl sb-sys:interactive-interrupt
      #+ccl  ccl:interrupt-signal-condition
      #+clisp system::simple-interrupt-condition
      #+ecl ext:interactive-interrupt
      #+allegro excl:interrupt-signal
      () (progn
           (format *error-output* "Aborting.~&")
           (clack:stop *server*)
           (uiop:quit)))
    (error (c) (format t "Woops, an unknown error occured:~&~a~&" c))))

I'm using SBCL 1.2.4.debian, I guess a first step would be to upgrade.

I've also seen lengthy discussion on pgloader's issue tracker, where he asks to try with CCL, known to have a better GC.

Do you have an idea of what could be the problem ? It seems to work with no input text, no search result and no macro… but that can't be this code, can it ?

joaotavora commented 6 years ago

but that can't be this code, can it ?

I don't believe it is, but of course it can, which doesn't mean it is.

Unfortunately, from the way you describe it, I can't tell you much more. But I can tell you:

I would continue narrowing it down. Does the problem manifest itself:

Alternatively, use the LDB prompt to carefully debug the problem. What kind of objects are created that are taking up so much heap? Maybe there's a clue there...

Also If I'm reading this correctly, your heap appears to be 1GB, which isn't too big. You should probably increase it, but I am no expert on SBCL, ask in #lisp or reddit or something. Are you on 32bit or 64bit.

vindarel commented 6 years ago

Basically, it's the same with those elements removed (removed lparalell, removed join-thread of hunchentoot from main, ran from Slime).

I forgot to say something, that the first error I got was a "maximum recursion depth exceeded". A few days later I shrank my code to the one given and got this heap exhausted error.

Running in Slime (still bad completion with Sly by default, didn't investigate) gives the same (but had not seen it's in the *inferior-lisp* buffer).

Roswell errors out on installing SBCL, cffi error on building for CCL…

use the LDB prompt to carefully debug the problem

have to learn that…

You should probably increase it, but I am no expert on SBCL, ask in #lisp or reddit or something.

ok

On Debian 64bits.

Thanks a lot ! (I'll post an update if I can. I suppose this is not linked to Snooze at all).

quick rant: But how many difficulties !

& quick edit: restarted my machine (now 6GB of free RAM and swap), built the executable with --dynamic-space-size 1024, tried again on Slime: the error occurs precisely when I click "enter" on the index. I never see a break on my second route.

but well first => with SBCL 1.4

joaotavora commented 6 years ago

Did you also rule out clack using SNOOZE:MAKE-HUNCHENTOOT-APP?

built the executable with --dynamic-space-size 1024, tried again on Slime:

1024 doesn't sound much larger than what you had previously. Try 2048.

And did you build an executable or run from SLIME?

maximum recursion depth exceeded

Did you get a backtrace when that happened? What did it show?

I never see a break on my second route.

Do you see it when you type "/torrents" directly in the URL bar?

I suppose this is not linked to Snooze at al

You cannot know that, naturally. You can put BREAK statements in SNOOZE::HANDLE-REQUEST if you are really suspicious.

still bad completion with Sly by default, didn't investigate

What symbol are you trying to complete?

When I get a chance I will try building a similar app and see if you can run it.

joaotavora commented 6 years ago

Hello @vindarel,

I have tried your code and come to the conclusion that the problem is indeed snooze, or, more specifically it's backtrace printing based on UIOP. Long story short, when pressing "Search" directly, you are trying to access the /torrents route without valid arguments. That's perfectly fine and snooze is trying to warn you about this, honouring the :verbose option you gave in (setf snooze:*catch-errors* :verbose). If it worked, it would try to warn you about the invalid arguments and also warn you that you don't yet have an EXPLAIN-CONDITION method to explain it (prettily) to a future user of your site.

But, in this particular case, the :verbose reporting fails miserably and gets into a recursive print-object error, which is why you get stack exhaustion or even the heap exhaustion.

I'm trying to figure out the best way to fix it in snooze, but in the meanwhile can you try adding this workaround to your code and trying again?


(let ((problematic-method (find-method #'print-object
                                       '(:after)
                                       `(,(find-class 'snooze::resignalled-condition)
                                         t))))
  (when problematic-method
    (common-lisp:remove-method #'print-object
                               problematic-method)))
joaotavora commented 6 years ago

So I should have resolved the problem! Thanks for all your persistence.

The :VERBOSE error message, while still not perfect, should now help you understand what's going on and what you have to add to your app (which is an explain-condition notifying the user that he's messing up the query parameters for the form).

And here's what you should see now (and should have seen two days ago instead of the heap exhaustion :-))

<ERROR-WHEN-EXPLAINING #<UNCONVERTIBLE-ARGUMENT 400: Malformed arg for resource TORRENTS>>

Here's a little bit more information: 

You got a #<ERROR-WHEN-EXPLAINING #<UNCONVERTIBLE-ARGUMENT 400: Malformed arg for resource TORRENTS>> because:

SNOOZE:EXPLAIN-CONDITION was trying to explain to the user the condition #<UNCONVERTIBLE-ARGUMENT 400: Malformed arg for resource TORRENTS>.

You got a #<UNCONVERTIBLE-ARGUMENT 400: Malformed arg for resource TORRENTS> because:

SNOOZE:URI-TO-ARGUMENTS was trying to make sense of the key-value-pair "search" and "" when it caught #<SNOOZE-READER-ERROR Can't read from an empty string>

No more interesting information on #<SNOOZE-READER-ERROR Can't read from an empty string>, sorry

Here's the backtrace at the time of the #<SNOOZE-READER-ERROR Can't read from an empty string>:...
vindarel commented 6 years ago

I tried, read an explicit error message, changed my parameter's name and all is well. Thanks and hurray ! :)

joaotavora commented 6 years ago

Good. I hope now you can tell me what exactly in SLY's completion puts you off :-)