Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Error when an audio file is loaded from a HTML5 <audio> control #146

Open
bayerf42 opened this issue Sep 18, 2018 · 5 comments
Open

Error when an audio file is loaded from a HTML5 <audio> control #146

bayerf42 opened this issue Sep 18, 2018 · 5 comments

Comments

@bayerf42
Copy link

When a browser download data from a HTML5 control, an error is produced when writing to the TCP stream. The exact error message is different with different OS/CL versions but the error occurs
every time. I tested

Probably has to do with HTTP code 206 "partial content"
Getting the whole file with wget etc. works fine

To reproduce this error,
start your Lisp, load the following file web.lisp and type (run)

Point your browser to http://localhost:8080/music.html
and check ./message.log and ./access.log afterwards

Sample logs created with CCL under Ubuntu:

access.log:

127.0.0.1 - [2017-12-30 19:23:35] "GET /music.html HTTP/1.1" 200 371 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:57.0) Gecko/20100101 Firefox/57.0"
127.0.0.1 - [2017-12-30 19:23:35] "GET /TomLehrerTheElements.ogg HTTP/1.1" 206 1406325 "http://localhost:8080/music.html" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:57.0) Gecko/20100101 Firefox/57.0"
127.0.0.1 - [2017-12-30 19:23:35] "GET /TomLehrerTheElements.ogg HTTP/1.1" 206 30069 "http://localhost:8080/music.html" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:57.0) Gecko/20100101 Firefox/57.0"
127.0.0.1 - [2017-12-30 19:23:35] "GET /TomLehrerTheElements.ogg HTTP/1.1" 206 1242485 "http://localhost:8080/music.html" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:57.0) Gecko/20100101 Firefox/57.0"
127.0.0.1 - [2017-12-30 19:23:35] "GET /favicon.ico HTTP/1.1" 404 190 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:57.0) Gecko/20100101 Firefox/57.0"

message.log:

[2017-12-30 19:23:35 [ERROR]] on #<BASIC-TCP-STREAM ISO-8859-1 (SOCKET/5) #x3020015EB15D>, within "-alive

" :
Broken pipe (error #32) during write
(7F4320901370) : 0 (PRINT-CALL-HISTORY :CONTEXT NIL :PROCESS NIL :ORIGIN NIL :DETAILED-P NIL :COUNT 1152921504606846975 :START-FRAME-NUMBER 0 :STREAM #<STRING-OUTPUT-STREAM #x30200160418D> :PRINT-LEVEL 2 :PRINT-LENGTH 5 :SHOW-INTERNAL-FRAMES NIL :FORMAT :TRADITIONAL) 869
(7F43209014D8) : 1 (PRINT-BACKTRACE-TO-STREAM #<STRING-OUTPUT-STREAM #x30200160418D>) 85
(7F4320901508) : 2 (GET-BACKTRACE) 389
(7F4320901570) : 3 (FUNCALL #'#<(:INTERNAL (HUNCHENTOOT:HANDLE-REQUEST (HUNCHENTOOT:ACCEPTOR HUNCHENTOOT:REQUEST)))> #<SOCKET-ERROR #x30200160457D>) 117
(7F43209015A0) : 4 (SIGNAL #<SOCKET-ERROR #x30200160457D>) 1021
(7F43209015F0) : 5 (%ERROR #<SOCKET-ERROR #x30200160457D> NIL 17490785731267) 117
(7F4320901618) : 6 (SOCKET-ERROR #<BASIC-TCP-STREAM ISO-8859-1 (SOCKET/5) #x3020015EB15D> "write" 32 NIL :CONNECT-ADDRESS NIL) 613
(7F4320901658) : 7 (FD-STREAM-FORCE-OUTPUT #<BASIC-TCP-STREAM ISO-8859-1 (SOCKET/5) #x3020015EB15D> #S(CCL::IOBLOCK :STREAM #<BASIC-TCP-STREAM ISO-8859-1 (SOCKET/5) #x3020015EB15D> :UNTYI-CHAR NIL ...) 4096 NIL) 1205
(7F43209016B8) : 8 (%IOBLOCK-BINARY-STREAM-WRITE-VECTOR #S(CCL::IOBLOCK :STREAM #<BASIC-TCP-STREAM ISO-8859-1 (SOCKET/5) #x3020015EB15D> :UNTYI-CHAR NIL ...) #(75 2 86 69 213 ...) 0 8192) 4749
(7F4320901748) : 9 (WRITE-SEQUENCE #(75 2 86 69 213 ...) #<BASIC-TCP-STREAM ISO-8859-1 (SOCKET/5) #x3020015EB15D> :START 0 :END 8192) 797
(7F4320901798) : 10 (HANDLE-STATIC-FILE #P"TomLehrerTheElements.ogg" "application/ogg") 1173
(7F4320901828) : 11 (%CALL-NEXT-METHOD (NIL #<STANDARD-METHOD HUNCHENTOOT:ACCEPTOR-DISPATCH-REQUEST #> . 17490785731368)) 1061
(7F43209018A0) : 12 (FUNCALL #'#<#<STANDARD-METHOD HUNCHENTOOT:ACCEPTOR-DISPATCH-REQUEST (HUNCHENTOOT:EASY-ACCEPTOR T)>> #<EASY-ACCEPTOR (host *, port 8080)> #<HUNCHENTOOT:REQUEST #x30200160CEAD>) 237
(7F43209018E0) : 13 (%%STANDARD-COMBINED-METHOD-DCODE (#<STANDARD-METHOD HUNCHENTOOT:ACCEPTOR-DISPATCH-REQUEST #> #<STANDARD-METHOD HUNCHENTOOT:ACCEPTOR-DISPATCH-REQUEST #>) 17490785731368) 749
(7F4320901958) : 14 (FUNCALL #'#<#<STANDARD-METHOD HUNCHENTOOT:HANDLE-REQUEST (HUNCHENTOOT:ACCEPTOR HUNCHENTOOT:REQUEST)>> #<EASY-ACCEPTOR (host *, port 8080)> #<HUNCHENTOOT:REQUEST #x30200160CEAD>) 877
(7F43209019F0) : 15 (FUNCALL #'#<#<STANDARD-METHOD HUNCHENTOOT:PROCESS-REQUEST (T)>> #<HUNCHENTOOT:REQUEST #x30200160CEAD>) 1781
(7F4320901AC8) : 16 (DO-WITH-ACCEPTOR-REQUEST-COUNT-INCREMENTED #<EASY-ACCEPTOR (host *, port 8080)> #<COMPILED-LEXICAL-CLOSURE (:INTERNAL #) #x30200160D50F>) 1237
(7F4320901B38) : 17 (FUNCALL #'#<#<STANDARD-METHOD HUNCHENTOOT:PROCESS-CONNECTION (HUNCHENTOOT:ACCEPTOR T)>> #<EASY-ACCEPTOR (host *, port 8080)> #<USOCKET:STREAM-USOCKET #x3020015EADDD>) 1757
(7F4320901C58) : 18 (%CALL-NEXT-METHOD (NIL #<STANDARD-METHOD HUNCHENTOOT:PROCESS-CONNECTION #> . 17490785731513)) 1061
(7F4320901CD0) : 19 (FUNCALL #'#<#<STANDARD-METHOD HUNCHENTOOT:PROCESS-CONNECTION :AROUND (HUNCHENTOOT:ACCEPTOR T)>> #<EASY-ACCEPTOR (host *, port 8080)> #<USOCKET:STREAM-USOCKET #x3020015EADDD>) 997
(7F4320901D68) : 20 (%%STANDARD-COMBINED-METHOD-DCODE (#<STANDARD-METHOD HUNCHENTOOT:PROCESS-CONNECTION :AROUND #> #<STANDARD-METHOD HUNCHENTOOT:PROCESS-CONNECTION #>) 17490785731513) 749
(7F4320901DE0) : 21 (FUNCALL #'#<(:INTERNAL HUNCHENTOOT::PROCESS-CONNECTION% (HUNCHENTOOT::HANDLE-INCOMING-CONNECTION% (HUNCHENTOOT:ONE-THREAD-PER-CONNECTION-TASKMASTER T)))> #<EASY-ACCEPTOR (host *, port 8080)> #<USOCKET:STREAM-USOCKET #x3020015EADDD>) 181
(7F4320901E40) : 22 (FUNCALL #'#<(:INTERNAL BORDEAUX-THREADS::BINDING-DEFAULT-SPECIALS)>) 837
(7F4320901E68) : 23 (RUN-PROCESS-INITIAL-FORM #<PROCESS hunchentoot-worker-127.0.0.1:37956(3) [Active] #x3020015EA57D> (#<COMPILED-LEXICAL-CLOSURE # #x3020015EA30F>)) 797
(7F4320901EF0) : 24 (FUNCALL #'#<(:INTERNAL (CCL::%PROCESS-PRESET-INTERNAL (PROCESS)))> #<PROCESS hunchentoot-worker-127.0.0.1:37956(3) [Active] #x3020015EA57D> (#<COMPILED-LEXICAL-CLOSURE # #x3020015EA30F>)) 581
(7F4320901F98) : 25 (FUNCALL #'#<(:INTERNAL CCL::THREAD-MAKE-STARTUP-FUNCTION)>) 277

web.lisp:

(in-package :cl-user)
(ql:quickload "hunchentoot")

(defparameter *htacc* nil)

(defun run ()
  (setf *htacc* 
	(make-instance
	 'hunchentoot:easy-acceptor :port 8080
	 :access-log-destination "./access.log"
	 :message-log-destination "./message.log"
	 :document-root "."))
  (setf hunchentoot:*show-lisp-errors-p* t)
  (setf hunchentoot:*show-lisp-backtraces-p* t)
  (hunchentoot:start *htacc*))

music.html:

<!DOCTYPE html>
  <head>
    <meta charset='utf-8'>
    <title>HT download test</title>
  </head>

  <body>
    <h2>Music</h2>
      <audio controls
             preload='auto'>
        <source src="any_big_audiofile.ogg" type='audio/ogg' />
        Sorry, no music.
      </audio>
  </body>
</html>
@hanshuebner
Copy link
Member

Is the problem the error message or is the content not properly delivered?

@bayerf42
Copy link
Author

The real problem is that this error occasionally totally locks down the web server so it has to be rebooted. I'm running it on Raspberry Pi as part of a bigger application and in this case the Pi cannot be accessed by ssh/Putty anymore. But the error is reproducible on Windows 7 and Ubuntu Linux, as well with CCL or SBCL and Chrome and Firefox.

@fjl
Copy link
Contributor

fjl commented Jul 6, 2019

I'm annoyed by this message, too. This happens anytime the browser cancels loading a resource.
The message is even worse on SBCL because it contains the content of the write buffer which is dumped into the error log, one decimal number per unwritten output byte.

I think Hunchentoot should just ignore write errors and close the connection if an error happens.

@stassats
Copy link
Member

stassats commented Jul 6, 2019

I think it should be ignored too.

@macrologist
Copy link

This isn't a real solution. In order to ignore this error I am using an altered version of handle-static-file:

(defun handle-static-file (pathname &optional content-type callback)
  "A function which acts like a Hunchentoot handler for the file
denoted by PATHNAME.  Sends a content type header corresponding to
CONTENT-TYPE or \(if that is NIL) tries to determine the content type
via the suffix of the file.
CALLBACK is run just before sending the file, and can be used
to set headers or check authorization;
arguments are the filename and the (guessed) content-type."
  (when (or (wild-pathname-p pathname)
            (not (fad:file-exists-p pathname))
            (fad:directory-exists-p pathname))
    ;; file does not exist
    (setf (return-code*) +http-not-found+)
    (abort-request-handler))
  (unless content-type
    (setf content-type (mime-type pathname)))
  (let ((time (or (file-write-date pathname)
                  (get-universal-time)))
        bytes-to-send)
    (setf (content-type*) (or (and content-type
                                   (maybe-add-charset-to-content-type-header content-type (reply-external-format*)))
                              "application/octet-stream")
          (header-out :last-modified) (rfc-1123-date time)
          (header-out :accept-ranges) "bytes")
    (handle-if-modified-since time)
    (unless (null callback)
      (funcall callback pathname content-type))
    (with-open-file (file pathname
                          :direction :input
                          :element-type 'octet)
      (setf bytes-to-send (maybe-handle-range-header file)
            (content-length*) bytes-to-send)
    ;; THIS IS THE HACKY PART    
   (handler-case 
          (let ((out (send-headers))
                (buf (make-array +buffer-length+ :element-type 'octet)))
            (loop
              (when (zerop bytes-to-send)
                (return))
              (let* ((chunk-size (min +buffer-length+ bytes-to-send)))
                (unless (eql chunk-size (read-sequence buf file :end chunk-size))
                  (error "can't read from input file"))
                (write-sequence buf out :end chunk-size)
                (decf bytes-to-send chunk-size)))
            (finish-output out))
        (error (e)
          (format *error-output* "Caught error while sending static file: ~a~%" e)
          nil)))))

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

5 participants