[hunchentoot-devel] Timing out when reading long post requests?

Hans Hübner hans.huebner at gmail.com
Wed Jul 6 13:23:30 UTC 2011


Oleg,

from looking at your backtrace it appears as if the client does not
send data for longer than the socket timeout.  What client do you use
to send the data?  Can you try other clients (wget, curl) or browsers?
 Same behaviour?

-Hans

On Wed, Jul 6, 2011 at 1:41 PM, Oleg Sivokon <olegsivokon at gmail.com> wrote:
> Hello, I'm not sure what is causing this error (please see the stack trace
> below), all I can say it's relatively big XML being sent. I must be doing
> something tremendously inefficient or else this error means something else,
> but I hope you would be able to advise:
> [2011-07-06 14:20:27 [ERROR]] I/O timeout reading #<SB-SYS:FD-STREAM for "a
> socket" {B8E0AA1}>.
> 0: (SB-DEBUG::MAP-BACKTRACE #<CLOSURE (LAMBDA #) {B9034D5}>)[:EXTERNAL]
> 1: (BACKTRACE 536870911 #<SB-IMPL::STRING-OUTPUT-STREAM {B903471}>)
> 2: (TRIVIAL-BACKTRACE:PRINT-BACKTRACE-TO-STREAM
>     #<SB-IMPL::STRING-OUTPUT-STREAM {B903471}>)
> 3: (HUNCHENTOOT::GET-BACKTRACE)
> 4: ((FLET #:LAMBDA284) #<SB-SYS:IO-TIMEOUT {B903139}>)
> 5: (SIGNAL #<SB-SYS:IO-TIMEOUT {B903139}>)[:EXTERNAL]
> 6: (ERROR SB-SYS:IO-TIMEOUT)[:EXTERNAL]
> 7: (SB-IMPL::SIGNAL-TIMEOUT SB-SYS:IO-TIMEOUT)[:EXTERNAL]
> 8: (SB-IMPL::REFILL-INPUT-BUFFER #<SB-SYS:FD-STREAM for "a socket"
> {B8E0AA1}>)
> 9: (SB-IMPL::FD-STREAM-READ-N-BYTES
>     #<SB-SYS:FD-STREAM for "a socket" {B8E0AA1}>
>     #(97 108 121 116 105 99 115 62 10 32 32 102 49 50 51 52 53 54 55 56 57
> 48
> . . . long array of data
> )
>     0
>     8191
>     NIL)
> 10: (SB-IMPL::ANSI-STREAM-READ-SEQUENCE
>      #(97 108 121 116 105 99 115 62 10 32 32 102 49 50 51 52 53 54 55 56 57
> 48
> . . . long array of data
> )
>      #<SB-SYS:FD-STREAM for "a socket" {B8E0AA1}>
>      0
>      8191)
> 11: (READ-SEQUENCE
>      #(97 108 121 116 105 99 115 62 10 32 32 102 49 50 51 52 53 54 55 56 57
> 48
> . . . long array of data
> )
>      #<SB-SYS:FD-STREAM for "a socket" {B8E0AA1}>)[:EXTERNAL]
> 12: ((SB-PCL::FAST-METHOD TRIVIAL-GRAY-STREAMS:STREAM-READ-SEQUENCE
>       (FLEXI-STREAMS:FLEXI-INPUT-STREAM T T T))
>      #<unavailable argument>
>      #<unavailable argument>
>      #<unavailable argument>
>      #<unavailable argument>
>      #<unavailable argument>
>      #<unavailable argument>)[:EXTERNAL]
> 13: ((LAMBDA
>          (SB-PCL::.PV. SB-PCL::.NEXT-METHOD-CALL. SB-PCL::.ARG0.
> SB-PCL::.ARG1.
>           SB-PCL::.ARG2. SB-PCL::.ARG3. SB-INT:&MORE
>           SB-PCL::.DFUN-MORE-CONTEXT. SB-PCL::.DFUN-MORE-COUNT.))
>      #<unused argument>
>      #<unused argument>
>      #<FLEXI-STREAMS:FLEXI-IO-STREAM {B8EA781}>
>      #(97 108 121 116 105 99 115 62 10 32 32 102 49 50 51 52 53 54 55 56 57
> 48
> . . . long array of data
> )
>      0
>      8191
>      -307111303
>      0)
> 14: (READ-SEQUENCE
>      #(97 108 121 116 105 99 115 62 10 32 32 102 49 50 51 52 53 54 55 56 57
> 48
> . . . long array of data
> )
>      #<FLEXI-STREAMS:FLEXI-IO-STREAM {B8EA781}>)[:EXTERNAL]
> 15: ((SB-PCL::FAST-METHOD RUNES::XSTREAM-UNDERFLOW (RUNES:XSTREAM))
>      #<unavailable argument>
>      #<unavailable argument>
>      #<RUNES:XSTREAM [main document :MAIN NIL]>)
> 16: (CXML::READ-NAME-TOKEN #<unavailable argument>)
> 17: (CXML::READ-TAG-2
>      #S(CXML::ZSTREAM
>         :TOKEN-CATEGORY :SEEN-<
>         :TOKEN-SEMANTIC NIL
>         :INPUT-STACK (#<RUNES:XSTREAM [main document :MAIN NIL]>))
>      #<RUNES:XSTREAM [main document :MAIN NIL]>
>      :STAG)
> 18: (CXML::FIX-SEEN-<
>      #S(CXML::ZSTREAM
>         :TOKEN-CATEGORY :SEEN-<
>         :TOKEN-SEMANTIC NIL
>         :INPUT-STACK (#<RUNES:XSTREAM [main document :MAIN NIL]>)))
> 19: (CXML::P/DOCUMENT
>      #S(CXML::ZSTREAM
>         :TOKEN-CATEGORY :SEEN-<
>         :TOKEN-SEMANTIC NIL
>         :INPUT-STACK (#<RUNES:XSTREAM [main document :MAIN NIL]>))
>      #<RUNE-DOM::DOM-BUILDER {B8EB0B9}>)[:EXTERNAL]
> 20: ((LAMBDA (CXML::ZSTREAM))
>      #S(CXML::ZSTREAM
>         :TOKEN-CATEGORY :SEEN-<
>         :TOKEN-SEMANTIC NIL
>         :INPUT-STACK (#<RUNES:XSTREAM [main document :MAIN NIL]>)))
> 21: (CXML::CALL-WITH-ZSTREAM
>      #<CLOSURE (LAMBDA #) {B8EE055}>
>      #S(CXML::ZSTREAM
>         :TOKEN-CATEGORY :SEEN-<
>         :TOKEN-SEMANTIC NIL
>         :INPUT-STACK (#<RUNES:XSTREAM [main document :MAIN NIL]>)))
> 22: (CXML::PARSE-XSTREAM
>      #<RUNES:XSTREAM [main document :MAIN NIL]>
>      #<RUNE-DOM::DOM-BUILDER {B8EB0B9}>)[:EXTERNAL]
> 23: (ROUNDS-WEB::ANALYTICS-SERVICE) ;;; This is my service I've posted the
> sources next
> 24: ((SB-PCL::FAST-METHOD HUNCHENTOOT:HANDLE-REQUEST
>       (HUNCHENTOOT:ACCEPTOR HUNCHENTOOT:REQUEST))
>      #<unavailable argument>
>      #<unavailable argument>
>      #<HUNCHENTOOT:ACCEPTOR (host *, port 8080)>
>      #<HUNCHENTOOT:REQUEST {B8E8A11}>)
> 25: ((SB-PCL::FAST-METHOD HUNCHENTOOT:PROCESS-REQUEST (T))
>      #<unavailable argument>
>      #<unavailable argument>
>      #<HUNCHENTOOT:REQUEST {B8E8A11}>)
> 26: ((SB-PCL::FAST-METHOD HUNCHENTOOT:PROCESS-CONNECTION
>       (HUNCHENTOOT:ACCEPTOR T))
>      #<unavailable argument>
>      #<unavailable argument>
>      #<HUNCHENTOOT:ACCEPTOR (host *, port 8080)>
>      #<USOCKET:STREAM-USOCKET {B8E0B31}>)
> 27: ((SB-PCL::FAST-METHOD HUNCHENTOOT:PROCESS-CONNECTION :AROUND
>       (HUNCHENTOOT:ACCEPTOR T))
>      #<unavailable argument>
>      #S(SB-PCL::FAST-METHOD-CALL
>         :FUNCTION #<FUNCTION #>
>         :PV NIL
>         :NEXT-METHOD-CALL NIL
>         :ARG-INFO (2))
>      #<HUNCHENTOOT:ACCEPTOR (host *, port 8080)>
>      #<USOCKET:STREAM-USOCKET {B8E0B31}>)
> 28: ((LAMBDA ()))
> 29: ((FLET #:WITHOUT-INTERRUPTS-BODY-[BLOCK353]358))
> 30: ((FLET SB-THREAD::WITH-MUTEX-THUNK))
> 31: ((FLET #:WITHOUT-INTERRUPTS-BODY-[CALL-WITH-MUTEX]267))
> 32: (SB-THREAD::CALL-WITH-MUTEX
>      #<CLOSURE (FLET SB-THREAD::WITH-MUTEX-THUNK) {B6C77205}>
>      #S(SB-THREAD:MUTEX
>         :NAME "thread result lock"
>         :%OWNER #<SB-THREAD:THREAD "Hunchentoot worker (client:
> 127.0.0.1:39378)" RUNNING {B8E2391}>
>         :STATE 1)
>      #<SB-THREAD:THREAD "Hunchentoot worker (client: 127.0.0.1:39378)"
> RUNNING {B8E2391}>
>      T)
> 33: ((LAMBDA ()))
> 34: ("foreign function: #x8066E3B")
> 35: ("foreign function: #x8052ABD")
> 36: ("foreign function: #x805DC00")
> 37: ("foreign function: #xB7FB696E")
> [2011-07-06 14:20:27 [ERROR]] Error while processing connection:
> #<SB-SYS:FD-STREAM for "a socket" {B8E0AA1}> is closed
>
> And here's the code for that service:
> (in-package :rounds-web)
> (defun split-no-last (subject by)
>   (loop with last = 0
>      for i = (position by subject :start last)
>      if i
>      collect (subseq subject last i) into parts and
>      do (setf last (1+ i))
>      else
>        when (> (1- (length subject)) last)
>        collect (subseq subject last) into parts
>        end and
>      return parts
>      end))
> (defun time-value (raw-value)
>   (let* ((pos (position #\. raw-value))
> (result (list (subseq raw-value 0 pos)))
> (raw-length (length raw-value)))
>     (if (< pos raw-length)
> (append result (list (subseq raw-value (1+ pos) raw-length)))
> result)))
> (defun parse-name (attribute)
>   ;; *round*, *category* and *event-type* are hash tables defined elsewhere
>   `(,(gethash (subseq attribute 0 1) *round*)
>      ,(gethash (subseq attribute 1 3) *category*)
>      ,(gethash (subseq attribute 3) *event-type*)))
> (defun print-attribute (stream attribute val)
>   (format stream "Event: Round ~a | Category ~a | Type ~a~&"
>  (first attribute)
>  (second attribute)
>  (third attribute))
>   (loop for v in val
>      for split = (time-value v)
>      for time = (first split)
>      for value = (if (> (length split) 1) (second split) nil)
>      do (format stream "    Time: ~a, Value: ~a~&" time value)))
> (defun save-parsed-events (xml)
>   (with-open-file (stream "./analytics.log"
>  :direction :output
>  :if-exists :supersede)
>     (loop for node across (dom:child-nodes xml)
>        do (when (eq (dom:node-type node) :element)
>    (format stream "VideoSessionId: ~a
> =========================================~&"
>    (subseq (dom:node-name node) 1))
>    (when (dom:attributes node)
>      (loop with attributes = (dom:attributes node)
> for n from 0 upto (1- (dom:length attributes))
> for attribute = (dom:item attributes n)
> do (print-attribute
>     stream (parse-name (dom:name attribute))
>     (split-no-last
>      (dom:get-attribute node (dom:name attribute)) #\,))))))))
> (defun analytics-service ()
>   (save-parsed-events
>    (dom:first-child
>     (cxml:parse-stream
>      (hunchentoot:raw-post-data
>       :request hunchentoot:*request*
>       :want-stream t)
>      (cxml-dom:make-dom-builder)))))
> This code isn't meant for production, all it does it mocks a real service
> which is meant to do the same thing so I could use it for testing, yet, I'd
> of course like it to work :)
> Please, if you have anything to suggest, I'd be very happy to hear!
> Thanks!
> Oleg
> _______________________________________________
> tbnl-devel site list
> tbnl-devel at common-lisp.net
> http://common-lisp.net/mailman/listinfo/tbnl-devel
>




More information about the Tbnl-devel mailing list