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

Oleg Sivokon olegsivokon at gmail.com
Wed Jul 6 11:41:50 UTC 2011


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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mailman.common-lisp.net/pipermail/tbnl-devel/attachments/20110706/e495a587/attachment.html>


More information about the Tbnl-devel mailing list