Subject: 24.3; url-http sometimes closes connection prematurely

From: James Stout <[email-masked]>
Date: Sat, 4 Jan 2014 13:01:02 -0800

Before I describe how to reproduce the bug, let me be clear: I know what's
causing it and I know how to fix it. Let me know and I will happily send a
fix. The core problem is that the http library uses an incorrect regular
expression when determining when the response headers are complete. It's
looking for an empty line, and it uses "^\r*$", but it should use "^\r?\n".
Because $ can match both the end of the buffer and newline, it may match
simply when the input has not yet all been received. By using the correct
regular expression, it will wait for the newline. The change from * to ? is
optional, I just did that for cleanliness.

The broken regular expression is at line 1040 of url-http.el. There is
another instance at line 1017.

To reproduce:

1. Run a Web server that returns a 204 (no content) response with a couple
headers. For example, run a simple Python http server (
http://docs.python.org/2/library/basehttpserver.html), and subclass the
handler to add the following method (note that send_response automatically
includes 2 headers).
def do_POST(self):
        self.send_response(204)  # no content
        self.end_headers()

2. Send a request to the server from Emacs. This is the code I used,
pointing it to my local server. The data didn't matter:
(defun send-post-data (url data)
  (let ((url-request-method "POST")
    (url-request-data data))
    (message "sending request: %.10f" (float-time))
    (url-retrieve url (lambda (status) (message "received response: %.10f"
(float-time))) nil t t)))

3. At this point I saw an error in the Python logs that the connection had
been unexpectedly closed during the send_response call, after it had sent
the status line, but before it had sent any header lines. In Emacs, the URL
debug logs explained what had happened:

http -> Calling after change function
`url-http-wait-for-headers-change-function' for `#<process localhost>'
http -> url-http-wait-for-headers-change-function ( *http localhost:9090*)
http -> Saw end of headers... ( *http localhost:9090*)
http -> url-http-parse-response called in ( *http localhost:9090*)
http -> 204 response must have headers only ( *http localhost:9090*).
http -> Marking connection as free: localhost:9090 #<process localhost>
http -> url-http-parse-headers called in ( *http localhost:9090*)
http -> url-http-parse-response called in ( *http localhost:9090*)
http -> Parsed HTTP headers: class=2 status=204
http -> Finished parsing HTTP headers: t
http -> Marking connection as free: localhost:9090 #<process localhost>
http -> Activating callback in buffer ( *http localhost:9090*)
http -> Spinning waiting for headers...

As you can see, it sees the end of the headers prematurely in the 3rd line
of the logs, and closes the connection shortly afterwards. I confirmed this
by printing the buffer contents at that point, and it had only received the
1st line of the response. No empty lines had been received, yet it believed
it was at the end of the headers.

If Emacs crashed, and you have the Emacs process in the gdb debugger,
please include the output from the following gdb commands:
    `bt full' and `xbacktrace'.
For information about debugging Emacs, please read the file
/usr/share/emacs/24.3/etc/DEBUG.

In GNU Emacs 24.3.1 (i686-pc-cygwin)
 of 2013-08-14 on moufang
Windowing system distributor `Microsoft Corp.', version 6.1.7601
Configured using:
 `configure
 '--srcdir=/home/kbrown/src/cygemacs/emacs-24.3-2/src/emacs-24.3'
 '--prefix=/usr' '--exec-prefix=/usr' '--bindir=/usr/bin'
 '--sbindir=/usr/sbin' '--libexecdir=/usr/libexec'
 '--datadir=/usr/share' '--localstatedir=/var' '--sysconfdir=/etc'
 '--datarootdir=/usr/share' '--docdir=/usr/share/doc/emacs' '-C'
 '--with-w32' 'CC=gcc' 'CFLAGS=-ggdb -O2 -pipe
 -fdebug-prefix-map=/home/kbrown/src/cygemacs/emacs-24.3-2/build=/usr/src/debug/emacs-24.3-2
 -fdebug-prefix-map=/home/kbrown/src/cygemacs/emacs-24.3-2/src/emacs-24.3=/usr/src/debug/emacs-24.3-2'
 'LDFLAGS=-L/usr/lib/ncursesw' 'LIBS='
 'CPPFLAGS=-I/usr/include/ncursesw''

Important settings:
  value of $LANG: en_US.UTF-8
  locale-coding-system: utf-8-unix
  default enable-multibyte-characters: t

Major mode: Fundamental

Minor modes in effect:
  show-paren-mode: t
  global-linum-mode: t
  ido-ubiquitous-mode: t
  ido-everywhere: t
  diff-auto-refine-mode: t
  global-auto-revert-mode: t
  recentf-mode: t
  tooltip-mode: t
  mouse-wheel-mode: t
  file-name-shadow-mode: t
  global-font-lock-mode: t
  blink-cursor-mode: t
  auto-composition-mode: t
  auto-encryption-mode: t
  auto-compression-mode: t
  column-number-mode: t
  line-number-mode: t
  transient-mark-mode: t

Recent input:
<down> <down> <down> <return> <end> <left> <left> <left>
<left> <left> <left> <left> <return> 1 <return> C-g
<up> <up> <up> <up> <up> <up> <up> <up> <up> <up> <up>
<up> <up> <up> <up> <up> <up> <up> <up> <up> <up> <up>
<up> <up> <up> <up> <up> <up> <up> <up> <up> <up> <up>
<up> <up> <up> <up> <up> <up> <up> <up> <up> <up> <up>
<up> <up> <up> <up> <up> <up> <up> <up> <up> <up> <up>
<left> <left> <return> y <return> y <return> y <return>
<backspace> <backspace> y <return> y <return> y <return>
C-g <next> <prior> C-x C-s y e s <return> C-x r b .
E m a c s <return> <C-end> C-x b C-g C-x b u r l <return>
C-x b u r l <return> <up> <up> <up> <up> <up> <up>
<up> <up> <up> <up> <up> <up> <up> <up> C-SPC <C-end>
M-w C-x b u n s c e n t e d <backspace> <backspace>
<backspace> <backspace> <backspace> <backspace> <backspace>
<return> <up> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <down> <down> C-x 0 C-x 0 C-x k <return> <C-home>
C-x k <return> y e s <return> M-x <right> <right>
<return>

Recent messages:
sending request: 1388866362.5328981876
received response: 1388866364.4430074692
sending request: 1388866368.1072170734
received response: 1388866369.4172918797
Auto-saving...done
Mark set
sending request: 1388866394.5217278004
received response: 1388866396.2348258495
byte-code: End of buffer [8 times]
byte-code: Attempt to delete minibuffer or sole ordinary window

Load-path shadows:
None found.

Features:
(url-handlers browse-url apropos cus-edit cus-start cus-load misearch
multi-isearch jka-compr find-func shadow sort mail-extr emacsbug message
rfc822 mml mml-sec mm-decode mm-bodies mm-encode mailabbrev gmm-utils
mailheader sendmail subword python rx mail-utils network-stream starttls
url-cache url-http tls mail-parse rfc2231 rfc2047 rfc2045 ietf-drums
url-gw url-auth url url-proxy url-privacy url-expand url-methods
url-history url-cookie url-domsuf url-util url-parse auth-source eieio
byte-opt bytecomp byte-compile cconv gnus-util mm-util mail-prsvr
password-cache url-vars mailcap vc-git bookmark pp linum-relative
cl-macs gv paren linum smex smartscan paredit edmacro kmacro uniquify
ido-ubiquitous cl advice help-fns advice-preload ido magit-key-mode
magit view help-mode grep compile comint format-spec epa derived epg
epg-config diff-mode cl-lib autorevert ansi-color git-rebase-mode
git-commit-mode server log-edit easy-mmode ring pcvs-util add-log
thingatpt recentf tree-widget wid-edit 4clojure-autoloads
clojure-test-mode-autoloads cider-autoloads clojure-mode-autoloads
find-file-in-project-autoloads ido-ubiquitous-autoloads
linum-relative-autoloads load-theme-buffer-local-autoloads
magit-autoloads info easymenu git-rebase-mode-autoloads
git-commit-mode-autoloads paredit-autoloads pkg-info-autoloads
epl-autoloads finder-inf dash-autoloads request-autoloads s-autoloads
smartscan-autoloads smex-autoloads package time-date tooltip ediff-hook
vc-hooks lisp-float-type mwheel w32-common-fns disp-table w32-win
w32-vars tool-bar dnd fontset image regexp-opt fringe tabulated-list
newcomment lisp-mode register page menu-bar rfn-eshadow timer select
scroll-bar mouse jit-lock font-lock syntax facemenu font-core frame cham
georgian utf-8-lang misc-lang vietnamese tibetan thai tai-viet lao
korean japanese hebrew greek romanian slovak czech european ethiopic
indian cyrillic chinese case-table epa-hook jka-cmpr-hook help simple
abbrev minibuffer loaddefs button faces cus-face macroexp files
text-properties overlay sha1 md5 base64 format env code-pages mule
custom widget hashtable-print-readable backquote make-network-process
dbusbind w32 multi-tty emacs)