hgweb: log error before attempting I/O

Previously, an uncaught exception during HTTP request serving would
attempt to send an error response then log the exception.

If an exception occurred during I/O, this exception would be
raised and the original exception wouldn't be logged.

This commit changes behavior so the original exception is logged
first, before we attempt to do anything else. This ensures the
exception is logged.

This change resulted in new tracebacks appearing in various tests.

Because tracebacks can vary between Python versions, we added a
simple script to filter the stack part of traceback lines. This
makes testing much simpler, as we don't need to glob over lines
and make lines conditional.

Differential Revision: https://phab.mercurial-scm.org/D5749

tests/filtertraceback.py

@@ -0,0 +1,29 b''
+#!/usr/bin/env python
+
+# Filters traceback lines from stdin.
+
+from __future__ import absolute_import, print_function
+
+import sys
+
+state = 'none'
+
+for line in sys.stdin:
+    if state == 'none':
+        if line.startswith('Traceback '):
+            state = 'tb'
+
+    elif state == 'tb':
+        if line.startswith('  File '):
+            state = 'file'
+            continue
+
+        elif not line.startswith(' '):
+            state = 'none'
+
+    elif state == 'file':
+        # Ignore lines after "  File "
+        state = 'tb'
+        continue
+
+    print(line, end='')

mercurial/hgweb/server.py

@@ -1,380 +1,383 b''
 # hgweb/server.py - The standalone hg web server.
 #
 # Copyright 21 May 2005 - (c) 2005 Jake Edge <[e-mail]>
 # Copyright 2005-2007 Matt Mackall <[e-mail]>
 #
 # This software may be used and distributed according to the terms of the
 # GNU General Public License version 2 or any later version.
 
 from __future__ import absolute_import
 
 import errno
 import os
 import socket
 import sys
 import traceback
 import wsgiref.validate
 
 from ..i18n import _
 
 from .. import (
     encoding,
     error,
     pycompat,
     util,
 )
 
 httpservermod = util.httpserver
 socketserver = util.socketserver
 urlerr = util.urlerr
 urlreq = util.urlreq
 
 from . import (
     common,
 )
 
 def _splitURI(uri):
     """Return path and query that has been split from uri
 
     Just like CGI environment, the path is unquoted, the query is
     not.
     """
     if r'?' in uri:
         path, query = uri.split(r'?', 1)
     else:
         path, query = uri, r''
     return urlreq.unquote(path), query
 
 class _error_logger(object):
     def __init__(self, handler):
         self.handler = handler
     def flush(self):
         pass
     def write(self, str):
         self.writelines(str.split('\n'))
     def writelines(self, seq):
         for msg in seq:
             self.handler.log_error(r"HG error:  %s", encoding.strfromlocal(msg))
 
 class _httprequesthandler(httpservermod.basehttprequesthandler):
 
     url_scheme = 'http'
 
     @staticmethod
     def preparehttpserver(httpserver, ui):
         """Prepare .socket of new HTTPServer instance"""
 
     def __init__(self, *args, **kargs):
         self.protocol_version = r'HTTP/1.1'
         httpservermod.basehttprequesthandler.__init__(self, *args, **kargs)
 
     def _log_any(self, fp, format, *args):
         fp.write(pycompat.sysbytes(
             r"%s - - [%s] %s" % (self.client_address[0],
                                  self.log_date_time_string(),
                                  format % args)) + '\n')
         fp.flush()
 
     def log_error(self, format, *args):
         self._log_any(self.server.errorlog, format, *args)
 
     def log_message(self, format, *args):
         self._log_any(self.server.accesslog, format, *args)
 
     def log_request(self, code=r'-', size=r'-'):
         xheaders = []
         if util.safehasattr(self, 'headers'):
             xheaders = [h for h in self.headers.items()
                         if h[0].startswith(r'x-')]
         self.log_message(r'"%s" %s %s%s',
                          self.requestline, str(code), str(size),
                          r''.join([r' %s:%s' % h for h in sorted(xheaders)]))
 
     def do_write(self):
         try:
             self.do_hgweb()
         except socket.error as inst:
             if inst.errno != errno.EPIPE:
                 raise
 
     def do_POST(self):
         try:
             self.do_write()
         except Exception:
-            self._start_response(r"500 Internal Server Error", [])
-            self._write(b"Internal Server Error")
-            self._done()
+            # I/O below could raise another exception. So log the original
+            # exception first to ensure it is recorded.
             tb = r"".join(traceback.format_exception(*sys.exc_info()))
             # We need a native-string newline to poke in the log
             # message, because we won't get a newline when using an
             # r-string. This is the easy way out.
             newline = chr(10)
             self.log_error(r"Exception happened during processing "
                            r"request '%s':%s%s", self.path, newline, tb)
 
+            self._start_response(r"500 Internal Server Error", [])
+            self._write(b"Internal Server Error")
+            self._done()
+
     def do_PUT(self):
         self.do_POST()
 
     def do_GET(self):
         self.do_POST()
 
     def do_hgweb(self):
         self.sent_headers = False
         path, query = _splitURI(self.path)
 
         # Ensure the slicing of path below is valid
         if (path != self.server.prefix
             and not path.startswith(self.server.prefix + b'/')):
             self._start_response(pycompat.strurl(common.statusmessage(404)),
                                  [])
             if self.command == 'POST':
                 # Paranoia: tell the client we're going to close the
                 # socket so they don't try and reuse a socket that
                 # might have a POST body waiting to confuse us. We do
                 # this by directly munging self.saved_headers because
                 # self._start_response ignores Connection headers.
                 self.saved_headers = [(r'Connection', r'Close')]
             self._write(b"Not Found")
             self._done()
             return
 
         env = {}
         env[r'GATEWAY_INTERFACE'] = r'CGI/1.1'
         env[r'REQUEST_METHOD'] = self.command
         env[r'SERVER_NAME'] = self.server.server_name
         env[r'SERVER_PORT'] = str(self.server.server_port)
         env[r'REQUEST_URI'] = self.path
         env[r'SCRIPT_NAME'] = pycompat.sysstr(self.server.prefix)
         env[r'PATH_INFO'] = pycompat.sysstr(path[len(self.server.prefix):])
         env[r'REMOTE_HOST'] = self.client_address[0]
         env[r'REMOTE_ADDR'] = self.client_address[0]
         env[r'QUERY_STRING'] = query or r''
 
         if pycompat.ispy3:
             if self.headers.get_content_type() is None:
                 env[r'CONTENT_TYPE'] = self.headers.get_default_type()
             else:
                 env[r'CONTENT_TYPE'] = self.headers.get_content_type()
             length = self.headers.get(r'content-length')
         else:
             if self.headers.typeheader is None:
                 env[r'CONTENT_TYPE'] = self.headers.type
             else:
                 env[r'CONTENT_TYPE'] = self.headers.typeheader
             length = self.headers.getheader(r'content-length')
         if length:
             env[r'CONTENT_LENGTH'] = length
         for header in [h for h in self.headers.keys()
                       if h.lower() not in (r'content-type', r'content-length')]:
             hkey = r'HTTP_' + header.replace(r'-', r'_').upper()
             hval = self.headers.get(header)
             hval = hval.replace(r'\n', r'').strip()
             if hval:
                 env[hkey] = hval
         env[r'SERVER_PROTOCOL'] = self.request_version
         env[r'wsgi.version'] = (1, 0)
         env[r'wsgi.url_scheme'] = pycompat.sysstr(self.url_scheme)
         if env.get(r'HTTP_EXPECT', '').lower() == '100-continue':
             self.rfile = common.continuereader(self.rfile, self.wfile.write)
 
         env[r'wsgi.input'] = self.rfile
         env[r'wsgi.errors'] = _error_logger(self)
         env[r'wsgi.multithread'] = isinstance(self.server,
                                              socketserver.ThreadingMixIn)
         if util.safehasattr(socketserver, 'ForkingMixIn'):
             env[r'wsgi.multiprocess'] = isinstance(self.server,
                                                    socketserver.ForkingMixIn)
         else:
             env[r'wsgi.multiprocess'] = False
 
         env[r'wsgi.run_once'] = 0
 
         wsgiref.validate.check_environ(env)
 
         self.saved_status = None
         self.saved_headers = []
         self.length = None
         self._chunked = None
         for chunk in self.server.application(env, self._start_response):
             self._write(chunk)
         if not self.sent_headers:
             self.send_headers()
         self._done()
 
     def send_headers(self):
         if not self.saved_status:
             raise AssertionError("Sending headers before "
                                  "start_response() called")
         saved_status = self.saved_status.split(None, 1)
         saved_status[0] = int(saved_status[0])
         self.send_response(*saved_status)
         self.length = None
         self._chunked = False
         for h in self.saved_headers:
             self.send_header(*h)
             if h[0].lower() == r'content-length':
                 self.length = int(h[1])
         if (self.length is None and
             saved_status[0] != common.HTTP_NOT_MODIFIED):
             self._chunked = (not self.close_connection and
                              self.request_version == r'HTTP/1.1')
             if self._chunked:
                 self.send_header(r'Transfer-Encoding', r'chunked')
             else:
                 self.send_header(r'Connection', r'close')
         self.end_headers()
         self.sent_headers = True
 
     def _start_response(self, http_status, headers, exc_info=None):
         assert isinstance(http_status, str)
         code, msg = http_status.split(None, 1)
         code = int(code)
         self.saved_status = http_status
         bad_headers = (r'connection', r'transfer-encoding')
         self.saved_headers = [h for h in headers
                               if h[0].lower() not in bad_headers]
         return self._write
 
     def _write(self, data):
         if not self.saved_status:
             raise AssertionError("data written before start_response() called")
         elif not self.sent_headers:
             self.send_headers()
         if self.length is not None:
             if len(data) > self.length:
                 raise AssertionError("Content-length header sent, but more "
                                      "bytes than specified are being written.")
             self.length = self.length - len(data)
         elif self._chunked and data:
             data = '%x\r\n%s\r\n' % (len(data), data)
         self.wfile.write(data)
         self.wfile.flush()
 
     def _done(self):
         if self._chunked:
             self.wfile.write('0\r\n\r\n')
             self.wfile.flush()
 
     def version_string(self):
         if self.server.serverheader:
             return encoding.strfromlocal(self.server.serverheader)
         return httpservermod.basehttprequesthandler.version_string(self)
 
 class _httprequesthandlerssl(_httprequesthandler):
     """HTTPS handler based on Python's ssl module"""
 
     url_scheme = 'https'
 
     @staticmethod
     def preparehttpserver(httpserver, ui):
         try:
             from .. import sslutil
             sslutil.modernssl
         except ImportError:
             raise error.Abort(_("SSL support is unavailable"))
 
         certfile = ui.config('web', 'certificate')
 
         # These config options are currently only meant for testing. Use
         # at your own risk.
         cafile = ui.config('devel', 'servercafile')
         reqcert = ui.configbool('devel', 'serverrequirecert')
 
         httpserver.socket = sslutil.wrapserversocket(httpserver.socket,
                                                      ui,
                                                      certfile=certfile,
                                                      cafile=cafile,
                                                      requireclientcert=reqcert)
 
     def setup(self):
         self.connection = self.request
         self.rfile = self.request.makefile(r"rb", self.rbufsize)
         self.wfile = self.request.makefile(r"wb", self.wbufsize)
 
 try:
     import threading
     threading.activeCount() # silence pyflakes and bypass demandimport
     _mixin = socketserver.ThreadingMixIn
 except ImportError:
     if util.safehasattr(os, "fork"):
         _mixin = socketserver.ForkingMixIn
     else:
         class _mixin(object):
             pass
 
 def openlog(opt, default):
     if opt and opt != '-':
         return open(opt, 'ab')
     return default
 
 class MercurialHTTPServer(_mixin, httpservermod.httpserver, object):
 
     # SO_REUSEADDR has broken semantics on windows
     if pycompat.iswindows:
         allow_reuse_address = 0
 
     def __init__(self, ui, app, addr, handler, **kwargs):
         httpservermod.httpserver.__init__(self, addr, handler, **kwargs)
         self.daemon_threads = True
         self.application = app
 
         handler.preparehttpserver(self, ui)
 
         prefix = ui.config('web', 'prefix')
         if prefix:
             prefix = '/' + prefix.strip('/')
         self.prefix = prefix
 
         alog = openlog(ui.config('web', 'accesslog'), ui.fout)
         elog = openlog(ui.config('web', 'errorlog'), ui.ferr)
         self.accesslog = alog
         self.errorlog = elog
 
         self.addr, self.port = self.socket.getsockname()[0:2]
         self.fqaddr = socket.getfqdn(addr[0])
 
         self.serverheader = ui.config('web', 'server-header')
 
 class IPv6HTTPServer(MercurialHTTPServer):
     address_family = getattr(socket, 'AF_INET6', None)
     def __init__(self, *args, **kwargs):
         if self.address_family is None:
             raise error.RepoError(_('IPv6 is not available on this system'))
         super(IPv6HTTPServer, self).__init__(*args, **kwargs)
 
 def create_server(ui, app):
 
     if ui.config('web', 'certificate'):
         handler = _httprequesthandlerssl
     else:
         handler = _httprequesthandler
 
     if ui.configbool('web', 'ipv6'):
         cls = IPv6HTTPServer
     else:
         cls = MercurialHTTPServer
 
     # ugly hack due to python issue5853 (for threaded use)
     try:
         import mimetypes
         mimetypes.init()
     except UnicodeDecodeError:
         # Python 2.x's mimetypes module attempts to decode strings
         # from Windows' ANSI APIs as ascii (fail), then re-encode them
         # as ascii (clown fail), because the default Python Unicode
         # codec is hardcoded as ascii.
 
         sys.argv # unwrap demand-loader so that reload() works
         reload(sys) # resurrect sys.setdefaultencoding()
         oldenc = sys.getdefaultencoding()
         sys.setdefaultencoding("latin1") # or any full 8-bit encoding
         mimetypes.init()
         sys.setdefaultencoding(oldenc)
 
     address = ui.config('web', 'address')
     port = util.getport(ui.config('web', 'port'))
     try:
         return cls(ui, app, (address, port), handler)
     except socket.error as inst:
         raise error.Abort(_("cannot start server at '%s:%d': %s")
                           % (address, port, encoding.strtolocal(inst.args[1])))

tests/test-hgweb.t

@@ -1,963 +1,979 b''
 #require serve
 
 Some tests for hgweb. Tests static files, plain files and different 404's.
 
   $ hg init test
   $ cd test
   $ mkdir da
   $ echo foo > da/foo
   $ echo foo > foo
   $ hg ci -Ambase
   adding da/foo
   adding foo
   $ hg bookmark -r0 '@'
   $ hg bookmark -r0 'a b c'
   $ hg bookmark -r0 'd/e/f'
   $ hg serve -n test -p $HGPORT -d --pid-file=hg.pid -A access.log -E errors.log
   $ cat hg.pid >> $DAEMON_PIDS
 
 manifest
 
   $ (get-with-headers.py localhost:$HGPORT 'file/tip/?style=raw')
   200 Script output follows
   
   
   drwxr-xr-x da
   -rw-r--r-- 4 foo
   
   
   $ (get-with-headers.py localhost:$HGPORT 'file/tip/da?style=raw')
   200 Script output follows
   
   
   -rw-r--r-- 4 foo
   
   
 
 plain file
 
   $ get-with-headers.py localhost:$HGPORT 'file/tip/foo?style=raw'
   200 Script output follows
   
   foo
 
 should give a 404 - static file that does not exist
 
   $ get-with-headers.py localhost:$HGPORT 'static/bogus'
   404 Not Found
   
   <!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.1//EN" "http://www.w3.org/TR/xhtml11/DTD/xhtml11.dtd">
   <html xmlns="http://www.w3.org/1999/xhtml" xml:lang="en-US">
   <head>
   <link rel="icon" href="/static/hgicon.png" type="image/png" />
   <meta name="robots" content="index, nofollow" />
   <link rel="stylesheet" href="/static/style-paper.css" type="text/css" />
   <script type="text/javascript" src="/static/mercurial.js"></script>
   
   <title>test: error</title>
   </head>
   <body>
   
   <div class="container">
   <div class="menu">
   <div class="logo">
   <a href="https://mercurial-scm.org/">
   <img src="/static/hglogo.png" width=75 height=90 border=0 alt="mercurial" /></a>
   </div>
   <ul>
   <li><a href="/shortlog">log</a></li>
   <li><a href="/graph">graph</a></li>
   <li><a href="/tags">tags</a></li>
   <li><a href="/bookmarks">bookmarks</a></li>
   <li><a href="/branches">branches</a></li>
   </ul>
   <ul>
   <li><a href="/help">help</a></li>
   </ul>
   </div>
   
   <div class="main">
   
   <h2 class="breadcrumb"><a href="/">Mercurial</a> </h2>
   <h3>error</h3>
   
   
   <form class="search" action="/log">
   
   <p><input name="rev" id="search1" type="text" size="30" value="" /></p>
   <div id="hint">Find changesets by keywords (author, files, the commit message), revision
   number or hash, or <a href="/help/revsets">revset expression</a>.</div>
   </form>
   
   <div class="description">
   <p>
   An error occurred while processing your request:
   </p>
   <p>
   Not Found
   </p>
   </div>
   </div>
   </div>
   
   
   
   </body>
   </html>
   
   [1]
 
 should give a 404 - bad revision
 
   $ get-with-headers.py localhost:$HGPORT 'file/spam/foo?style=raw'
   404 Not Found
   
   
   error: revision not found: spam
   [1]
 
 should give a 400 - bad command
 
   $ get-with-headers.py localhost:$HGPORT 'file/tip/foo?cmd=spam&style=raw'
   400* (glob)
   
   
   error: no such method: spam
   [1]
 
   $ get-with-headers.py --headeronly localhost:$HGPORT '?cmd=spam'
   400 no such method: spam
   [1]
 
 should give a 400 - bad command as a part of url path (issue4071)
 
   $ get-with-headers.py --headeronly localhost:$HGPORT 'spam'
   400 no such method: spam
   [1]
 
   $ get-with-headers.py --headeronly localhost:$HGPORT 'raw-spam'
   400 no such method: spam
   [1]
 
   $ get-with-headers.py --headeronly localhost:$HGPORT 'spam/tip/foo'
   400 no such method: spam
   [1]
 
 should give a 404 - file does not exist
 
   $ get-with-headers.py localhost:$HGPORT 'file/tip/bork?style=raw'
   404 Not Found
   
   
   error: bork@2ef0ac749a14: not found in manifest
   [1]
   $ get-with-headers.py localhost:$HGPORT 'file/tip/bork'
   404 Not Found
   
   <!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.1//EN" "http://www.w3.org/TR/xhtml11/DTD/xhtml11.dtd">
   <html xmlns="http://www.w3.org/1999/xhtml" xml:lang="en-US">
   <head>
   <link rel="icon" href="/static/hgicon.png" type="image/png" />
   <meta name="robots" content="index, nofollow" />
   <link rel="stylesheet" href="/static/style-paper.css" type="text/css" />
   <script type="text/javascript" src="/static/mercurial.js"></script>
   
   <title>test: error</title>
   </head>
   <body>
   
   <div class="container">
   <div class="menu">
   <div class="logo">
   <a href="https://mercurial-scm.org/">
   <img src="/static/hglogo.png" width=75 height=90 border=0 alt="mercurial" /></a>
   </div>
   <ul>
   <li><a href="/shortlog">log</a></li>
   <li><a href="/graph">graph</a></li>
   <li><a href="/tags">tags</a></li>
   <li><a href="/bookmarks">bookmarks</a></li>
   <li><a href="/branches">branches</a></li>
   </ul>
   <ul>
   <li><a href="/help">help</a></li>
   </ul>
   </div>
   
   <div class="main">
   
   <h2 class="breadcrumb"><a href="/">Mercurial</a> </h2>
   <h3>error</h3>
   
   
   <form class="search" action="/log">
   
   <p><input name="rev" id="search1" type="text" size="30" value="" /></p>
   <div id="hint">Find changesets by keywords (author, files, the commit message), revision
   number or hash, or <a href="/help/revsets">revset expression</a>.</div>
   </form>
   
   <div class="description">
   <p>
   An error occurred while processing your request:
   </p>
   <p>
   bork@2ef0ac749a14: not found in manifest
   </p>
   </div>
   </div>
   </div>
   
   
   
   </body>
   </html>
   
   [1]
   $ get-with-headers.py localhost:$HGPORT 'diff/tip/bork?style=raw'
   404 Not Found
   
   
   error: bork@2ef0ac749a14: not found in manifest
   [1]
 
 try bad style
 
   $ (get-with-headers.py localhost:$HGPORT 'file/tip/?style=foobar')
   200 Script output follows
   
   <!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.1//EN" "http://www.w3.org/TR/xhtml11/DTD/xhtml11.dtd">
   <html xmlns="http://www.w3.org/1999/xhtml" xml:lang="en-US">
   <head>
   <link rel="icon" href="/static/hgicon.png" type="image/png" />
   <meta name="robots" content="index, nofollow" />
   <link rel="stylesheet" href="/static/style-paper.css" type="text/css" />
   <script type="text/javascript" src="/static/mercurial.js"></script>
   
   <title>test: 2ef0ac749a14 /</title>
   </head>
   <body>
   
   <div class="container">
   <div class="menu">
   <div class="logo">
   <a href="https://mercurial-scm.org/">
   <img src="/static/hglogo.png" alt="mercurial" /></a>
   </div>
   <ul>
   <li><a href="/shortlog/tip">log</a></li>
   <li><a href="/graph/tip">graph</a></li>
   <li><a href="/tags">tags</a></li>
   <li><a href="/bookmarks">bookmarks</a></li>
   <li><a href="/branches">branches</a></li>
   </ul>
   <ul>
   <li><a href="/rev/tip">changeset</a></li>
   <li class="active">browse</li>
   </ul>
   <ul>
   
   </ul>
   <ul>
    <li><a href="/help">help</a></li>
   </ul>
   </div>
   
   <div class="main">
   <h2 class="breadcrumb"><a href="/">Mercurial</a> </h2>
   <h3>
    directory / @ 0:<a href="/rev/2ef0ac749a14">2ef0ac749a14</a>
    <span class="phase">draft</span> <span class="branchhead">default</span> <span class="tag">tip</span> <span class="tag">@</span> <span class="tag">a b c</span> <span class="tag">d/e/f</span> 
   </h3>
   
   
   <form class="search" action="/log">
   
   <p><input name="rev" id="search1" type="text" size="30" value="" /></p>
   <div id="hint">Find changesets by keywords (author, files, the commit message), revision
   number or hash, or <a href="/help/revsets">revset expression</a>.</div>
   </form>
   
   <table class="bigtable">
   <thead>
   <tr>
     <th class="name">name</th>
     <th class="size">size</th>
     <th class="permissions">permissions</th>
   </tr>
   </thead>
   <tbody class="stripes2">
   
   
   <tr class="fileline">
   <td class="name">
   <a href="/file/tip/da">
   <img src="/static/coal-folder.png" alt="dir."/> da/
   </a>
   <a href="/file/tip/da/">
   
   </a>
   </td>
   <td class="size"></td>
   <td class="permissions">drwxr-xr-x</td>
   </tr>
   
   <tr class="fileline">
   <td class="filename">
   <a href="/file/tip/foo">
   <img src="/static/coal-file.png" alt="file"/> foo
   </a>
   </td>
   <td class="size">4</td>
   <td class="permissions">-rw-r--r--</td>
   </tr>
   </tbody>
   </table>
   </div>
   </div>
   
   
   </body>
   </html>
   
 
 stop and restart
 
   $ killdaemons.py
   $ hg serve -p $HGPORT -d --pid-file=hg.pid -A access.log
   $ cat hg.pid >> $DAEMON_PIDS
 
 Test the access/error files are opened in append mode
 
   $ "$PYTHON" -c "from __future__ import print_function; print(len(open('access.log', 'rb').readlines()), 'log lines written')"
   14 log lines written
 
 static file
 
   $ get-with-headers.py --twice localhost:$HGPORT 'static/style-gitweb.css' - date etag server
   200 Script output follows
   content-length: 9074
   content-type: text/css
   
   body { font-family: sans-serif; font-size: 12px; border:solid #d9d8d1; border-width:1px; margin:10px; background: white; color: black; }
   a { color:#0000cc; }
   a:hover, a:visited, a:active { color:#880000; }
   div.page_header { height:25px; padding:8px; font-size:18px; font-weight:bold; background-color:#d9d8d1; }
   div.page_header a:visited { color:#0000cc; }
   div.page_header a:hover { color:#880000; }
   div.page_nav {
       padding:8px;
       display: flex;
       justify-content: space-between;
       align-items: center;
   }
   div.page_nav a:visited { color:#0000cc; }
   div.extra_nav {
       padding: 8px;
   }
   div.extra_nav a:visited {
       color: #0000cc;
   }
   div.page_path { padding:8px; border:solid #d9d8d1; border-width:0px 0px 1px}
   div.page_footer { padding:4px 8px; background-color: #d9d8d1; }
   div.page_footer_text { float:left; color:#555555; font-style:italic; }
   div.page_body { padding:8px; }
   div.title, a.title {
   	display:block; padding:6px 8px;
   	font-weight:bold; background-color:#edece6; text-decoration:none; color:#000000;
   }
   a.title:hover { background-color: #d9d8d1; }
   div.title_text { padding:6px 0px; border: solid #d9d8d1; border-width:0px 0px 1px; }
   div.log_body { padding:8px 8px 8px 150px; }
   .age { white-space:nowrap; }
   a.title span.age { position:relative; float:left; width:142px; font-style:italic; }
   div.log_link {
   	padding:0px 8px;
   	font-size:10px; font-family:sans-serif; font-style:normal;
   	position:relative; float:left; width:136px;
   }
   div.list_head { padding:6px 8px 4px; border:solid #d9d8d1; border-width:1px 0px 0px; font-style:italic; }
   a.list { text-decoration:none; color:#000000; }
   a.list:hover { text-decoration:underline; color:#880000; }
   table { padding:8px 4px; }
   th { padding:2px 5px; font-size:12px; text-align:left; }
   .parity0 { background-color:#ffffff; }
   tr.dark, .parity1, pre.sourcelines.stripes > :nth-child(4n+4) { background-color:#f6f6f0; }
   tr.light:hover, .parity0:hover, tr.dark:hover, .parity1:hover,
   pre.sourcelines.stripes > :nth-child(4n+2):hover,
   pre.sourcelines.stripes > :nth-child(4n+4):hover,
   pre.sourcelines.stripes > :nth-child(4n+1):hover + :nth-child(4n+2),
   pre.sourcelines.stripes > :nth-child(4n+3):hover + :nth-child(4n+4) { background-color:#edece6; }
   td { padding:2px 5px; font-size:12px; vertical-align:top; }
   td.closed { background-color: #99f; }
   td.link { padding:2px 5px; font-family:sans-serif; font-size:10px; }
   td.indexlinks { white-space: nowrap; }
   td.indexlinks a {
     padding: 2px 5px; line-height: 10px;
     border: 1px solid;
     color: #ffffff; background-color: #7777bb;
     border-color: #aaaadd #333366 #333366 #aaaadd;
     font-weight: bold;  text-align: center; text-decoration: none;
     font-size: 10px;
   }
   td.indexlinks a:hover { background-color: #6666aa; }
   div.pre { font-family:monospace; font-size:12px; white-space:pre; }
   
   .search {
       margin-right: 8px;
   }
   
   div#hint {
     position: absolute;
     display: none;
     width: 250px;
     padding: 5px;
     background: #ffc;
     border: 1px solid yellow;
     border-radius: 5px;
     z-index: 15;
   }
   
   #searchform:hover div#hint { display: block; }
   
   tr.thisrev a { color:#999999; text-decoration: none; }
   tr.thisrev pre { color:#009900; }
   td.annotate {
     white-space: nowrap;
   }
   div.annotate-info {
     z-index: 5;
     display: none;
     position: absolute;
     background-color: #FFFFFF;
     border: 1px solid #d9d8d1;
     text-align: left;
     color: #000000;
     padding: 5px;
   }
   div.annotate-info a { color: #0000FF; text-decoration: underline; }
   td.annotate:hover div.annotate-info { display: inline; }
   
   #diffopts-form {
     padding-left: 8px;
     display: none;
   }
   
   .linenr { color:#999999; text-decoration:none }
   div.rss_logo { float: right; white-space: nowrap; }
   div.rss_logo a {
   	padding:3px 6px; line-height:10px;
   	border:1px solid; border-color:#fcc7a5 #7d3302 #3e1a01 #ff954e;
   	color:#ffffff; background-color:#ff6600;
   	font-weight:bold; font-family:sans-serif; font-size:10px;
   	text-align:center; text-decoration:none;
   }
   div.rss_logo a:hover { background-color:#ee5500; }
   pre { margin: 0; }
   span.logtags span {
   	padding: 0px 4px;
   	font-size: 10px;
   	font-weight: normal;
   	border: 1px solid;
   	background-color: #ffaaff;
   	border-color: #ffccff #ff00ee #ff00ee #ffccff;
   }
   span.logtags span.phasetag {
   	background-color: #dfafff;
   	border-color: #e2b8ff #ce48ff #ce48ff #e2b8ff;
   }
   span.logtags span.obsoletetag {
   	background-color: #dddddd;
   	border-color: #e4e4e4 #a3a3a3 #a3a3a3 #e4e4e4;
   }
   span.logtags span.instabilitytag {
   	background-color: #ffb1c0;
   	border-color: #ffbbc8 #ff4476 #ff4476 #ffbbc8;
   }
   span.logtags span.tagtag {
   	background-color: #ffffaa;
   	border-color: #ffffcc #ffee00 #ffee00 #ffffcc;
   }
   span.logtags span.branchtag {
   	background-color: #aaffaa;
   	border-color: #ccffcc #00cc33 #00cc33 #ccffcc;
   }
   span.logtags span.inbranchtag {
   	background-color: #d5dde6;
   	border-color: #e3ecf4 #9398f4 #9398f4 #e3ecf4;
   }
   span.logtags span.bookmarktag {
   	background-color: #afdffa;
   	border-color: #ccecff #46ace6 #46ace6 #ccecff;
   }
   span.difflineplus { color:#008800; }
   span.difflineminus { color:#cc0000; }
   span.difflineat { color:#990099; }
   div.diffblocks { counter-reset: lineno; }
   div.diffblock { counter-increment: lineno; }
   pre.sourcelines { position: relative; counter-reset: lineno; }
   pre.sourcelines > span {
   	display: inline-block;
   	box-sizing: border-box;
   	width: 100%;
   	padding: 0 0 0 5em;
   	counter-increment: lineno;
   	vertical-align: top;
   }
   pre.sourcelines > span:before {
   	-moz-user-select: -moz-none;
   	-khtml-user-select: none;
   	-webkit-user-select: none;
   	-ms-user-select: none;
   	user-select: none;
   	display: inline-block;
   	margin-left: -6em;
   	width: 4em;
   	color: #999;
   	text-align: right;
   	content: counters(lineno,".");
   	float: left;
   }
   pre.sourcelines > a {
   	display: inline-block;
   	position: absolute;
   	left: 0px;
   	width: 4em;
   	height: 1em;
   }
   tr:target td,
   pre.sourcelines > span:target,
   pre.sourcelines.stripes > span:target {
   	background-color: #bfdfff;
   }
   
   .description {
       font-family: monospace;
       white-space: pre;
   }
   
   /* Followlines */
   tbody.sourcelines > tr.followlines-selected,
   pre.sourcelines > span.followlines-selected {
     background-color: #99C7E9 !important;
   }
   
   div#followlines {
     background-color: #FFF;
     border: 1px solid #d9d8d1;
     padding: 5px;
     position: fixed;
   }
   
   div.followlines-cancel {
     text-align: right;
   }
   
   div.followlines-cancel > button {
     line-height: 80%;
     padding: 0;
     border: 0;
     border-radius: 2px;
     background-color: inherit;
     font-weight: bold;
   }
   
   div.followlines-cancel > button:hover {
     color: #FFFFFF;
     background-color: #CF1F1F;
   }
   
   div.followlines-link {
     margin: 2px;
     margin-top: 4px;
     font-family: sans-serif;
   }
   
   .btn-followlines {
     position: absolute;
     display: none;
     cursor: pointer;
     box-sizing: content-box;
     font-size: 11px;
     width: 13px;
     height: 13px;
     border-radius: 3px;
     margin: 0px;
     margin-top: -2px;
     padding: 0px;
     background-color: #E5FDE5;
     border: 1px solid #9BC19B;
     font-family: monospace;
     text-align: center;
     line-height: 5px;
   }
   
   span.followlines-select .btn-followlines {
     margin-left: -1.6em;
   }
   
   .btn-followlines:hover {
     transform: scale(1.1, 1.1);
   }
   
   .btn-followlines .followlines-plus {
     color: green;
   }
   
   .btn-followlines .followlines-minus {
     color: red;
   }
   
   .btn-followlines-end {
     background-color: #ffdcdc;
   }
   
   .sourcelines tr:hover .btn-followlines,
   .sourcelines span.followlines-select:hover > .btn-followlines {
     display: inline;
   }
   
   .btn-followlines-hidden,
   .sourcelines tr:hover .btn-followlines-hidden {
     display: none;
   }
   
   /* Graph */
   div#wrapper {
   	position: relative;
   	margin: 0;
   	padding: 0;
   	margin-top: 3px;
   }
   
   canvas {
   	position: absolute;
   	z-index: 5;
   	top: -0.9em;
   	margin: 0;
   }
   
   ul#graphnodes {
   	list-style: none inside none;
   	padding: 0;
   	margin: 0;
   }
   
   ul#graphnodes li {
   	position: relative;
   	height: 37px;
   	overflow: visible;
   	padding-top: 2px;
   }
   
   ul#graphnodes li .fg {
   	position: absolute;
   	z-index: 10;
   }
   
   ul#graphnodes li .info {
   	font-size: 100%;
   	font-style: italic;
   }
   
   /* Comparison */
   .legend {
       padding: 1.5% 0 1.5% 0;
   }
   
   .legendinfo {
       border: 1px solid #d9d8d1;
       font-size: 80%;
       text-align: center;
       padding: 0.5%;
   }
   
   .equal {
       background-color: #ffffff;
   }
   
   .delete {
       background-color: #faa;
       color: #333;
   }
   
   .insert {
       background-color: #ffa;
   }
   
   .replace {
       background-color: #e8e8e8;
   }
   
   .comparison {
       overflow-x: auto;
   }
   
   .header th {
       text-align: center;
   }
   
   .block {
       border-top: 1px solid #d9d8d1;
   }
   
   .scroll-loading {
     -webkit-animation: change_color 1s linear 0s infinite alternate;
     -moz-animation: change_color 1s linear 0s infinite alternate;
     -o-animation: change_color 1s linear 0s infinite alternate;
     animation: change_color 1s linear 0s infinite alternate;
   }
   
   @-webkit-keyframes change_color {
     from { background-color: #A0CEFF; } to {  }
   }
   @-moz-keyframes change_color {
     from { background-color: #A0CEFF; } to {  }
   }
   @-o-keyframes change_color {
     from { background-color: #A0CEFF; } to {  }
   }
   @keyframes change_color {
     from { background-color: #A0CEFF; } to {  }
   }
   
   .scroll-loading-error {
       background-color: #FFCCCC !important;
   }
   
   #doc {
       margin: 0 8px;
   }
   304 Not Modified
   
 
 phase changes are refreshed (issue4061)
 
   $ echo bar >> foo
   $ hg ci -msecret --secret
   $ get-with-headers.py localhost:$HGPORT 'log?style=raw'
   200 Script output follows
   
   
   # HG changelog
   # Node ID 2ef0ac749a14e4f57a5a822464a0902c6f7f448f
   
   changeset:   2ef0ac749a14e4f57a5a822464a0902c6f7f448f
   revision:    0
   user:        test
   date:        Thu, 01 Jan 1970 00:00:00 +0000
   summary:     base
   branch:      default
   tag:         tip
   bookmark:    @
   bookmark:    a b c
   bookmark:    d/e/f
   
   
   $ hg phase --draft tip
   $ get-with-headers.py localhost:$HGPORT 'log?style=raw'
   200 Script output follows
   
   
   # HG changelog
   # Node ID a084749e708a9c4c0a5b652a2a446322ce290e04
   
   changeset:   a084749e708a9c4c0a5b652a2a446322ce290e04
   revision:    1
   user:        test
   date:        Thu, 01 Jan 1970 00:00:00 +0000
   summary:     secret
   branch:      default
   tag:         tip
   
   changeset:   2ef0ac749a14e4f57a5a822464a0902c6f7f448f
   revision:    0
   user:        test
   date:        Thu, 01 Jan 1970 00:00:00 +0000
   summary:     base
   bookmark:    @
   bookmark:    a b c
   bookmark:    d/e/f
   
   
 
 access bookmarks
 
   $ get-with-headers.py localhost:$HGPORT 'rev/@?style=paper' | egrep '^200|changeset 0:'
   200 Script output follows
    changeset 0:<a href="/rev/2ef0ac749a14?style=paper">2ef0ac749a14</a>
 
   $ get-with-headers.py localhost:$HGPORT 'rev/%40?style=paper' | egrep '^200|changeset 0:'
   200 Script output follows
    changeset 0:<a href="/rev/2ef0ac749a14?style=paper">2ef0ac749a14</a>
 
   $ get-with-headers.py localhost:$HGPORT 'rev/a%20b%20c?style=paper' | egrep '^200|changeset 0:'
   200 Script output follows
    changeset 0:<a href="/rev/2ef0ac749a14?style=paper">2ef0ac749a14</a>
 
   $ get-with-headers.py localhost:$HGPORT 'rev/d%252Fe%252Ff?style=paper' | egrep '^200|changeset 0:'
   200 Script output follows
    changeset 0:<a href="/rev/2ef0ac749a14?style=paper">2ef0ac749a14</a>
 
 no '[up]' entry in file view when in root directory
 
   $ get-with-headers.py localhost:$HGPORT 'file/tip?style=paper' | grep -F '[up]'
   [1]
   $ get-with-headers.py localhost:$HGPORT 'file/tip/da?style=paper' | grep -F '[up]'
   <a href="/file/tip/?style=paper">[up]</a>
   $ get-with-headers.py localhost:$HGPORT 'file/tip?style=coal' | grep -F '[up]'
   [1]
   $ get-with-headers.py localhost:$HGPORT 'file/tip/da?style=coal' | grep -F '[up]'
   <a href="/file/tip/?style=coal">[up]</a>
   $ get-with-headers.py localhost:$HGPORT 'file/tip?style=gitweb' | grep -F '[up]'
   [1]
   $ get-with-headers.py localhost:$HGPORT 'file/tip/da?style=gitweb' | grep -F '[up]'
   <a href="/file/tip/?style=gitweb">[up]</a>
   $ get-with-headers.py localhost:$HGPORT 'file/tip?style=monoblue' | grep -F '[up]'
   [1]
   $ get-with-headers.py localhost:$HGPORT 'file/tip/da?style=monoblue' | grep -F '[up]'
   <a href="/file/tip/?style=monoblue">[up]</a>
   $ get-with-headers.py localhost:$HGPORT 'file/tip?style=spartan' | grep -F '[up]'
   [1]
   $ get-with-headers.py localhost:$HGPORT 'file/tip/da?style=spartan' | grep -F '[up]'
   <a href="/file/tip/?style=spartan">[up]</a>
 
 no style can be loaded from directories other than the specified paths
 
   $ mkdir -p x/templates/fallback
   $ cat <<EOF > x/templates/fallback/map
   > default = 'shortlog'
   > shortlog = 'fall back to default\n'
   > mimetype = 'text/plain'
   > EOF
   $ cat <<EOF > x/map
   > default = 'shortlog'
   > shortlog = 'access to outside of templates directory\n'
   > mimetype = 'text/plain'
   > EOF
 
   $ killdaemons.py
   $ hg serve -p $HGPORT -d --pid-file=hg.pid -A access.log -E errors.log \
   > --config web.style=fallback --config web.templates=x/templates
   $ cat hg.pid >> $DAEMON_PIDS
 
   $ get-with-headers.py localhost:$HGPORT "?style=`pwd`/x"
   200 Script output follows
   
   fall back to default
 
   $ get-with-headers.py localhost:$HGPORT '?style=..'
   200 Script output follows
   
   fall back to default
 
   $ get-with-headers.py localhost:$HGPORT '?style=./..'
   200 Script output follows
   
   fall back to default
 
   $ get-with-headers.py localhost:$HGPORT '?style=.../.../'
   200 Script output follows
   
   fall back to default
 
   $ killdaemons.py
 
 Test signal-safe-lock in web and non-web processes
 
   $ cat <<'EOF' > disablesig.py
   > import signal
   > from mercurial import error, extensions
   > def disabledsig(orig, signalnum, handler):
   >     if signalnum == signal.SIGTERM:
   >         raise error.Abort(b'SIGTERM cannot be replaced')
   >     try:
   >         return orig(signalnum, handler)
   >     except ValueError:
   >         raise error.Abort(b'signal.signal() called in thread?')
   > def uisetup(ui):
   >    extensions.wrapfunction(signal, b'signal', disabledsig)
   > EOF
 
  by default, signal interrupt should be disabled while making a lock file
 
   $ hg debuglock -s --config extensions.disablesig=disablesig.py
   abort: SIGTERM cannot be replaced
   [255]
 
  but in hgweb, it isn't disabled since some WSGI servers complains about
  unsupported signal.signal() calls (see issue5889)
 
   $ hg serve --config extensions.disablesig=disablesig.py \
   > --config web.allow-push='*' --config web.push_ssl=False \
   > -p $HGPORT -d --pid-file=hg.pid -A access.log -E errors.log
   $ cat hg.pid >> $DAEMON_PIDS
 
   $ hg clone -q http://localhost:$HGPORT/ repo
   $ hg bookmark -R repo foo
 
  push would fail if signal.signal() were called
 
   $ hg push -R repo -B foo
   pushing to http://localhost:$HGPORT/
   searching for changes
   no changes found
   exporting bookmark foo
   [1]
 
   $ rm -R repo
   $ killdaemons.py
 
 errors
 
-  $ cat errors.log
+  $ cat errors.log | "$PYTHON" $TESTDIR/filtertraceback.py
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=spam': (glob)
+  Traceback (most recent call last):
+  error: [Errno 104] $ECONNRESET$
+  
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/spam': (glob)
+  Traceback (most recent call last):
+  error: [Errno 104] $ECONNRESET$
+  
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/spam/tip/foo': (glob)
+  Traceback (most recent call last):
+  error: [Errno 104] $ECONNRESET$
+  
+  $ rm -f errors.log
 
 Uncaught exceptions result in a logged error and canned HTTP response
 
   $ hg serve --config extensions.hgweberror=$TESTDIR/hgweberror.py -p $HGPORT -d --pid-file=hg.pid -A access.log -E errors.log
   $ cat hg.pid >> $DAEMON_PIDS
 
   $ get-with-headers.py localhost:$HGPORT 'raiseerror' transfer-encoding content-type
   500 Internal Server Error
   transfer-encoding: chunked
   
   Internal Server Error (no-eol)
   [1]
 
   $ killdaemons.py
-  $ head -1 errors.log
+  $ cat errors.log | "$PYTHON" $TESTDIR/filtertraceback.py
   .* Exception happened during processing request '/raiseerror': (re)
+  Traceback (most recent call last):
+  AttributeError: I am an uncaught error!
+  
 
 Uncaught exception after partial content sent
 
   $ hg serve --config extensions.hgweberror=$TESTDIR/hgweberror.py -p $HGPORT -d --pid-file=hg.pid -A access.log -E errors.log
   $ cat hg.pid >> $DAEMON_PIDS
   $ get-with-headers.py localhost:$HGPORT 'raiseerror?partialresponse=1' transfer-encoding content-type
   200 Script output follows
   transfer-encoding: chunked
   content-type: text/plain
   
   partial content
   Internal Server Error (no-eol)
 
   $ killdaemons.py
 
 HTTP 304 works with hgwebdir (issue5844)
 
   $ cat > hgweb.conf << EOF
   > [paths]
   > /repo = $TESTTMP/test
   > EOF
 
   $ hg serve --web-conf hgweb.conf -p $HGPORT -d --pid-file hg.pid -E error.log
   $ cat hg.pid >> $DAEMON_PIDS
 
   $ get-with-headers.py --twice --headeronly localhost:$HGPORT 'repo/static/style.css' - date etag server
   200 Script output follows
   content-length: 2677
   content-type: text/css
   304 Not Modified
 
   $ killdaemons.py
 
   $ cd ..

tests/test-http-bad-server.t

@@ -1,936 +1,1008 b''
 #require serve zstd
 
 Client version is embedded in HTTP request and is effectively dynamic. Pin the
 version so behavior is deterministic.
 
   $ cat > fakeversion.py << EOF
   > from mercurial import util
   > util.version = lambda: b'4.2'
   > EOF
 
   $ cat >> $HGRCPATH << EOF
   > [extensions]
   > fakeversion = `pwd`/fakeversion.py
   > [format]
   > sparse-revlog = no
   > [devel]
   > legacy.exchange = phases
   > EOF
 
   $ hg init server0
   $ cd server0
   $ touch foo
   $ hg -q commit -A -m initial
 
 Also disable compression because zstd is optional and causes output to vary
 and because debugging partial responses is hard when compression is involved
 
   $ cat > .hg/hgrc << EOF
   > [extensions]
   > badserver = $TESTDIR/badserverext.py
   > [server]
   > compressionengines = none
   > EOF
 
 Failure to accept() socket should result in connection related error message
 
   $ hg serve --config badserver.closebeforeaccept=true -p $HGPORT -d --pid-file=hg.pid
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   abort: error: (\$ECONNRESET\$|\$EADDRNOTAVAIL\$) (re)
   [255]
 
 (The server exits on its own, but there is a race between that and starting a new server.
 So ensure the process is dead.)
 
   $ killdaemons.py $DAEMON_PIDS
 
 Failure immediately after accept() should yield connection related error message
 
   $ hg serve --config badserver.closeafteraccept=true -p $HGPORT -d --pid-file=hg.pid
   $ cat hg.pid > $DAEMON_PIDS
 
 TODO: this usually outputs good results, but sometimes emits abort:
 error: '' on FreeBSD and OS X.
 What we ideally want are:
 
 abort: error: $ECONNRESET$
 
 The flakiness in this output was observable easily with
 --runs-per-test=20 on macOS 10.12 during the freeze for 4.2.
   $ hg clone http://localhost:$HGPORT/ clone
   abort: error: * (glob)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
 Failure to read all bytes in initial HTTP request should yield connection related error message
 
   $ hg serve --config badserver.closeafterrecvbytes=1 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   abort: error: bad HTTP status line: * (glob)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
   $ cat error.log
   readline(1 from 65537) -> (1) G
   read limit reached; closing socket
 
   $ rm -f error.log
 
 Same failure, but server reads full HTTP request line
 
   $ hg serve --config badserver.closeafterrecvbytes=40 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
   $ hg clone http://localhost:$HGPORT/ clone
   abort: error: bad HTTP status line: * (glob)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
   $ cat error.log
   readline(40 from 65537) -> (33) GET /?cmd=capabilities HTTP/1.1\r\n
   readline(7 from -1) -> (7) Accept-
   read limit reached; closing socket
 
   $ rm -f error.log
 
 Failure on subsequent HTTP request on the same socket (cmd?batch)
 
   $ hg serve --config badserver.closeafterrecvbytes=210,223 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
   $ hg clone http://localhost:$HGPORT/ clone
   abort: error: bad HTTP status line: * (glob)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
   $ cat error.log
   readline(210 from 65537) -> (33) GET /?cmd=capabilities HTTP/1.1\r\n
   readline(177 from -1) -> (27) Accept-Encoding: identity\r\n
   readline(150 from -1) -> (35) accept: application/mercurial-0.1\r\n
   readline(115 from -1) -> (*) host: localhost:$HGPORT\r\n (glob)
   readline(* from -1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n (glob)
   readline(* from -1) -> (2) \r\n (glob)
   write(36) -> HTTP/1.1 200 Script output follows\r\n
   write(23) -> Server: badhttpserver\r\n
   write(37) -> Date: $HTTP_DATE$\r\n
   write(41) -> Content-Type: application/mercurial-0.1\r\n
   write(21) -> Content-Length: 450\r\n
   write(2) -> \r\n
   write(450) -> batch branchmap $USUAL_BUNDLE2_CAPS_NO_PHASES$ changegroupsubset compression=none getbundle httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx known lookup pushkey streamreqs=generaldelta,revlogv1 unbundle=HG10GZ,HG10BZ,HG10UN unbundlehash
   readline(4? from 65537) -> (26) GET /?cmd=batch HTTP/1.1\r\n (glob)
   readline(1? from -1) -> (1?) Accept-Encoding* (glob)
   read limit reached; closing socket
   readline(223 from 65537) -> (26) GET /?cmd=batch HTTP/1.1\r\n
   readline(197 from -1) -> (27) Accept-Encoding: identity\r\n
   readline(170 from -1) -> (29) vary: X-HgArg-1,X-HgProto-1\r\n
   readline(141 from -1) -> (41) x-hgarg-1: cmds=heads+%3Bknown+nodes%3D\r\n
   readline(100 from -1) -> (61) x-hgproto-1: 0.1 0.2 comp=$USUAL_COMPRESSIONS$ partial-pull\r\n
   readline(39 from -1) -> (35) accept: application/mercurial-0.1\r\n
   readline(4 from -1) -> (4) host
   read limit reached; closing socket
 
   $ rm -f error.log
 
 Failure to read getbundle HTTP request
 
   $ hg serve --config badserver.closeafterrecvbytes=308,317,304 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
   $ hg clone http://localhost:$HGPORT/ clone
   requesting all changes
   abort: error: bad HTTP status line: * (glob)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
   $ cat error.log
   readline(1 from -1) -> (1) x (?)
   readline(1 from -1) -> (1) x (?)
   readline(308 from 65537) -> (33) GET /?cmd=capabilities HTTP/1.1\r\n
   readline(275 from -1) -> (27) Accept-Encoding: identity\r\n
   readline(248 from -1) -> (35) accept: application/mercurial-0.1\r\n
   readline(213 from -1) -> (*) host: localhost:$HGPORT\r\n (glob)
   readline(* from -1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n (glob)
   readline(* from -1) -> (2) \r\n (glob)
   write(36) -> HTTP/1.1 200 Script output follows\r\n
   write(23) -> Server: badhttpserver\r\n
   write(37) -> Date: $HTTP_DATE$\r\n
   write(41) -> Content-Type: application/mercurial-0.1\r\n
   write(21) -> Content-Length: 450\r\n
   write(2) -> \r\n
   write(450) -> batch branchmap $USUAL_BUNDLE2_CAPS_NO_PHASES$ changegroupsubset compression=none getbundle httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx known lookup pushkey streamreqs=generaldelta,revlogv1 unbundle=HG10GZ,HG10BZ,HG10UN unbundlehash
   readline(13? from 65537) -> (26) GET /?cmd=batch HTTP/1.1\r\n (glob)
   readline(1?? from -1) -> (27) Accept-Encoding: identity\r\n (glob)
   readline(8? from -1) -> (29) vary: X-HgArg-1,X-HgProto-1\r\n (glob)
   readline(5? from -1) -> (41) x-hgarg-1: cmds=heads+%3Bknown+nodes%3D\r\n (glob)
   readline(1? from -1) -> (1?) x-hgproto-1:* (glob)
   read limit reached; closing socket
   readline(317 from 65537) -> (26) GET /?cmd=batch HTTP/1.1\r\n
   readline(291 from -1) -> (27) Accept-Encoding: identity\r\n
   readline(264 from -1) -> (29) vary: X-HgArg-1,X-HgProto-1\r\n
   readline(235 from -1) -> (41) x-hgarg-1: cmds=heads+%3Bknown+nodes%3D\r\n
   readline(194 from -1) -> (61) x-hgproto-1: 0.1 0.2 comp=$USUAL_COMPRESSIONS$ partial-pull\r\n
   readline(133 from -1) -> (35) accept: application/mercurial-0.1\r\n
   readline(98 from -1) -> (*) host: localhost:$HGPORT\r\n (glob)
   readline(* from -1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n (glob)
   readline(* from -1) -> (2) \r\n (glob)
   write(36) -> HTTP/1.1 200 Script output follows\r\n
   write(23) -> Server: badhttpserver\r\n
   write(37) -> Date: $HTTP_DATE$\r\n
   write(41) -> Content-Type: application/mercurial-0.1\r\n
   write(20) -> Content-Length: 42\r\n
   write(2) -> \r\n
   write(42) -> 96ee1d7354c4ad7372047672c36a1f561e3a6a4c\n;
   readline(* from 65537) -> (*) GET /?cmd=getbundle HTTP* (glob)
   read limit reached; closing socket
   readline(304 from 65537) -> (30) GET /?cmd=getbundle HTTP/1.1\r\n
   readline(274 from -1) -> (27) Accept-Encoding: identity\r\n
   readline(247 from -1) -> (29) vary: X-HgArg-1,X-HgProto-1\r\n
   readline(218 from -1) -> (218) x-hgarg-1: bookmarks=1&bundlecaps=HG20%2Cbundle2%3DHG20%250Abookmarks%250Achangegroup%253D01%252C02%250Adigests%253Dmd5%252Csha1%252Csha512%250Aerror%253Dabort%252Cunsupportedcontent%252Cpushraced%252Cpushkey%250Ahgtag
   read limit reached; closing socket
 
   $ rm -f error.log
 
 Now do a variation using POST to send arguments
 
   $ hg serve --config experimental.httppostargs=true --config badserver.closeafterrecvbytes=329,344 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   abort: error: bad HTTP status line: * (glob)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ cat error.log
+  $ cat error.log | "$PYTHON" $TESTDIR/filtertraceback.py
   readline(329 from 65537) -> (33) GET /?cmd=capabilities HTTP/1.1\r\n
   readline(296 from -1) -> (27) Accept-Encoding: identity\r\n
   readline(269 from -1) -> (35) accept: application/mercurial-0.1\r\n
   readline(234 from -1) -> (2?) host: localhost:$HGPORT\r\n (glob)
   readline(* from -1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n (glob)
   readline(* from -1) -> (2) \r\n (glob)
   write(36) -> HTTP/1.1 200 Script output follows\r\n
   write(23) -> Server: badhttpserver\r\n
   write(37) -> Date: $HTTP_DATE$\r\n
   write(41) -> Content-Type: application/mercurial-0.1\r\n
   write(21) -> Content-Length: 463\r\n
   write(2) -> \r\n
   write(463) -> batch branchmap $USUAL_BUNDLE2_CAPS_NO_PHASES$ changegroupsubset compression=none getbundle httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx httppostargs known lookup pushkey streamreqs=generaldelta,revlogv1 unbundle=HG10GZ,HG10BZ,HG10UN unbundlehash
   readline(1?? from 65537) -> (27) POST /?cmd=batch HTTP/1.1\r\n (glob)
   readline(1?? from -1) -> (27) Accept-Encoding: identity\r\n (glob)
   readline(1?? from -1) -> (41) content-type: application/mercurial-0.1\r\n (glob)
   readline(6? from -1) -> (33) vary: X-HgArgs-Post,X-HgProto-1\r\n (glob)
   readline(3? from -1) -> (19) x-hgargs-post: 28\r\n (glob)
   readline(1? from -1) -> (1?) x-hgproto-1: * (glob)
   read limit reached; closing socket
   readline(344 from 65537) -> (27) POST /?cmd=batch HTTP/1.1\r\n
   readline(317 from -1) -> (27) Accept-Encoding: identity\r\n
   readline(290 from -1) -> (41) content-type: application/mercurial-0.1\r\n
   readline(249 from -1) -> (33) vary: X-HgArgs-Post,X-HgProto-1\r\n
   readline(216 from -1) -> (19) x-hgargs-post: 28\r\n
   readline(197 from -1) -> (61) x-hgproto-1: 0.1 0.2 comp=$USUAL_COMPRESSIONS$ partial-pull\r\n
   readline(136 from -1) -> (35) accept: application/mercurial-0.1\r\n
   readline(101 from -1) -> (20) content-length: 28\r\n
   readline(81 from -1) -> (*) host: localhost:$HGPORT\r\n (glob)
   readline(* from -1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n (glob)
   readline(* from -1) -> (2) \r\n (glob)
   read(* from 28) -> (*) cmds=* (glob)
   read limit reached, closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=batch': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after receiving N bytes
+  
   write(36) -> HTTP/1.1 500 Internal Server Error\r\n
 
   $ rm -f error.log
 
 Now move on to partial server responses
 
 Server sends a single character from the HTTP response line
 
   $ hg serve --config badserver.closeaftersendbytes=1 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   abort: error: bad HTTP status line: H
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ cat error.log
+  $ cat error.log | "$PYTHON" $TESTDIR/filtertraceback.py
   readline(65537) -> (33) GET /?cmd=capabilities HTTP/1.1\r\n
   readline(-1) -> (27) Accept-Encoding: identity\r\n
   readline(-1) -> (35) accept: application/mercurial-0.1\r\n
   readline(-1) -> (2?) host: localhost:$HGPORT\r\n (glob)
   readline(-1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n
   readline(-1) -> (2) \r\n
   write(1 from 36) -> (0) H
   write limit reached; closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=capabilities': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
   write(36) -> HTTP/1.1 500 Internal Server Error\r\n
 
   $ rm -f error.log
 
 Server sends an incomplete capabilities response body
 
   $ hg serve --config badserver.closeaftersendbytes=180 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   abort: HTTP request error (incomplete response; expected 450 bytes got 20)
   (this may be an intermittent network failure; if the error persists, consider contacting the network or server operator)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ cat error.log
+  $ cat error.log | "$PYTHON" $TESTDIR/filtertraceback.py
   readline(65537) -> (33) GET /?cmd=capabilities HTTP/1.1\r\n
   readline(-1) -> (27) Accept-Encoding: identity\r\n
   readline(-1) -> (35) accept: application/mercurial-0.1\r\n
   readline(-1) -> (2?) host: localhost:$HGPORT\r\n (glob)
   readline(-1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n
   readline(-1) -> (2) \r\n
   write(36 from 36) -> (144) HTTP/1.1 200 Script output follows\r\n
   write(23 from 23) -> (121) Server: badhttpserver\r\n
   write(37 from 37) -> (84) Date: $HTTP_DATE$\r\n
   write(41 from 41) -> (43) Content-Type: application/mercurial-0.1\r\n
   write(21 from 21) -> (22) Content-Length: 450\r\n
   write(2 from 2) -> (20) \r\n
   write(20 from 450) -> (0) batch branchmap bund
   write limit reached; closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=capabilities': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
 
   $ rm -f error.log
 
 Server sends incomplete headers for batch request
 
   $ hg serve --config badserver.closeaftersendbytes=728 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
 TODO this output is horrible
 
   $ hg clone http://localhost:$HGPORT/ clone
   abort: 'http://localhost:$HGPORT/' does not appear to be an hg repository:
   ---%<--- (applicat)
   
   ---%<---
   !
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ cat error.log
+  $ cat error.log | "$PYTHON" $TESTDIR/filtertraceback.py
   readline(65537) -> (33) GET /?cmd=capabilities HTTP/1.1\r\n
   readline(-1) -> (27) Accept-Encoding: identity\r\n
   readline(-1) -> (35) accept: application/mercurial-0.1\r\n
   readline(-1) -> (2?) host: localhost:$HGPORT\r\n (glob)
   readline(-1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n
   readline(-1) -> (2) \r\n
   write(36 from 36) -> (692) HTTP/1.1 200 Script output follows\r\n
   write(23 from 23) -> (669) Server: badhttpserver\r\n
   write(37 from 37) -> (632) Date: $HTTP_DATE$\r\n
   write(41 from 41) -> (591) Content-Type: application/mercurial-0.1\r\n
   write(21 from 21) -> (570) Content-Length: 450\r\n
   write(2 from 2) -> (568) \r\n
   write(450 from 450) -> (118) batch branchmap $USUAL_BUNDLE2_CAPS_NO_PHASES$ changegroupsubset compression=none getbundle httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx known lookup pushkey streamreqs=generaldelta,revlogv1 unbundle=HG10GZ,HG10BZ,HG10UN unbundlehash
   readline(65537) -> (26) GET /?cmd=batch HTTP/1.1\r\n
   readline(-1) -> (27) Accept-Encoding: identity\r\n
   readline(-1) -> (29) vary: X-HgArg-1,X-HgProto-1\r\n
   readline(-1) -> (41) x-hgarg-1: cmds=heads+%3Bknown+nodes%3D\r\n
   readline(-1) -> (61) x-hgproto-1: 0.1 0.2 comp=$USUAL_COMPRESSIONS$ partial-pull\r\n
   readline(-1) -> (35) accept: application/mercurial-0.1\r\n
   readline(-1) -> (2?) host: localhost:$HGPORT\r\n (glob)
   readline(-1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n
   readline(-1) -> (2) \r\n
   write(36 from 36) -> (82) HTTP/1.1 200 Script output follows\r\n
   write(23 from 23) -> (59) Server: badhttpserver\r\n
   write(37 from 37) -> (22) Date: $HTTP_DATE$\r\n
   write(22 from 41) -> (0) Content-Type: applicat
   write limit reached; closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=batch': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
   write(36) -> HTTP/1.1 500 Internal Server Error\r\n
 
   $ rm -f error.log
 
 Server sends an incomplete HTTP response body to batch request
 
   $ hg serve --config badserver.closeaftersendbytes=793 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
 TODO client spews a stack due to uncaught ValueError in batch.results()
 #if no-chg
   $ hg clone http://localhost:$HGPORT/ clone 2> /dev/null
   [1]
 #else
   $ hg clone http://localhost:$HGPORT/ clone 2> /dev/null
   [255]
 #endif
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ cat error.log
+  $ cat error.log | "$PYTHON" $TESTDIR/filtertraceback.py
   readline(65537) -> (33) GET /?cmd=capabilities HTTP/1.1\r\n
   readline(-1) -> (27) Accept-Encoding: identity\r\n
   readline(-1) -> (35) accept: application/mercurial-0.1\r\n
   readline(-1) -> (2?) host: localhost:$HGPORT\r\n (glob)
   readline(-1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n
   readline(-1) -> (2) \r\n
   write(36 from 36) -> (757) HTTP/1.1 200 Script output follows\r\n
   write(23 from 23) -> (734) Server: badhttpserver\r\n
   write(37 from 37) -> (697) Date: $HTTP_DATE$\r\n
   write(41 from 41) -> (656) Content-Type: application/mercurial-0.1\r\n
   write(21 from 21) -> (635) Content-Length: 450\r\n
   write(2 from 2) -> (633) \r\n
   write(450 from 450) -> (183) batch branchmap $USUAL_BUNDLE2_CAPS_NO_PHASES$ changegroupsubset compression=none getbundle httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx known lookup pushkey streamreqs=generaldelta,revlogv1 unbundle=HG10GZ,HG10BZ,HG10UN unbundlehash
   readline(65537) -> (26) GET /?cmd=batch HTTP/1.1\r\n
   readline(-1) -> (27) Accept-Encoding: identity\r\n
   readline(-1) -> (29) vary: X-HgArg-1,X-HgProto-1\r\n
   readline(-1) -> (41) x-hgarg-1: cmds=heads+%3Bknown+nodes%3D\r\n
   readline(-1) -> (61) x-hgproto-1: 0.1 0.2 comp=$USUAL_COMPRESSIONS$ partial-pull\r\n
   readline(-1) -> (35) accept: application/mercurial-0.1\r\n
   readline(-1) -> (2?) host: localhost:$HGPORT\r\n (glob)
   readline(-1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n
   readline(-1) -> (2) \r\n
   write(36 from 36) -> (147) HTTP/1.1 200 Script output follows\r\n
   write(23 from 23) -> (124) Server: badhttpserver\r\n
   write(37 from 37) -> (87) Date: $HTTP_DATE$\r\n
   write(41 from 41) -> (46) Content-Type: application/mercurial-0.1\r\n
   write(20 from 20) -> (26) Content-Length: 42\r\n
   write(2 from 2) -> (24) \r\n
   write(24 from 42) -> (0) 96ee1d7354c4ad7372047672
   write limit reached; closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=batch': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
 
   $ rm -f error.log
 
 Server sends incomplete headers for getbundle response
 
   $ hg serve --config badserver.closeaftersendbytes=940 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
 TODO this output is terrible
 
   $ hg clone http://localhost:$HGPORT/ clone
   requesting all changes
   abort: 'http://localhost:$HGPORT/' does not appear to be an hg repository:
   ---%<--- (application/mercuri)
   
   ---%<---
   !
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ cat error.log
+  $ cat error.log | "$PYTHON" $TESTDIR/filtertraceback.py
   readline(65537) -> (33) GET /?cmd=capabilities HTTP/1.1\r\n
   readline(-1) -> (27) Accept-Encoding: identity\r\n
   readline(-1) -> (35) accept: application/mercurial-0.1\r\n
   readline(-1) -> (2?) host: localhost:$HGPORT\r\n (glob)
   readline(-1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n
   readline(-1) -> (2) \r\n
   write(36 from 36) -> (904) HTTP/1.1 200 Script output follows\r\n
   write(23 from 23) -> (881) Server: badhttpserver\r\n
   write(37 from 37) -> (844) Date: $HTTP_DATE$\r\n
   write(41 from 41) -> (803) Content-Type: application/mercurial-0.1\r\n
   write(21 from 21) -> (782) Content-Length: 450\r\n
   write(2 from 2) -> (780) \r\n
   write(450 from 450) -> (330) batch branchmap $USUAL_BUNDLE2_CAPS_NO_PHASES$ changegroupsubset compression=none getbundle httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx known lookup pushkey streamreqs=generaldelta,revlogv1 unbundle=HG10GZ,HG10BZ,HG10UN unbundlehash
   readline(65537) -> (26) GET /?cmd=batch HTTP/1.1\r\n
   readline(-1) -> (27) Accept-Encoding: identity\r\n
   readline(-1) -> (29) vary: X-HgArg-1,X-HgProto-1\r\n
   readline(-1) -> (41) x-hgarg-1: cmds=heads+%3Bknown+nodes%3D\r\n
   readline(-1) -> (61) x-hgproto-1: 0.1 0.2 comp=$USUAL_COMPRESSIONS$ partial-pull\r\n
   readline(-1) -> (35) accept: application/mercurial-0.1\r\n
   readline(-1) -> (2?) host: localhost:$HGPORT\r\n (glob)
   readline(-1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n
   readline(-1) -> (2) \r\n
   write(36 from 36) -> (294) HTTP/1.1 200 Script output follows\r\n
   write(23 from 23) -> (271) Server: badhttpserver\r\n
   write(37 from 37) -> (234) Date: $HTTP_DATE$\r\n
   write(41 from 41) -> (193) Content-Type: application/mercurial-0.1\r\n
   write(20 from 20) -> (173) Content-Length: 42\r\n
   write(2 from 2) -> (171) \r\n
   write(42 from 42) -> (129) 96ee1d7354c4ad7372047672c36a1f561e3a6a4c\n;
   readline(65537) -> (30) GET /?cmd=getbundle HTTP/1.1\r\n
   readline(-1) -> (27) Accept-Encoding: identity\r\n
   readline(-1) -> (29) vary: X-HgArg-1,X-HgProto-1\r\n
   readline(-1) -> (461) x-hgarg-1: bookmarks=1&bundlecaps=HG20%2Cbundle2%3DHG20%250Abookmarks%250Achangegroup%253D01%252C02%250Adigests%253Dmd5%252Csha1%252Csha512%250Aerror%253Dabort%252Cunsupportedcontent%252Cpushraced%252Cpushkey%250Ahgtagsfnodes%250Alistkeys%250Apushkey%250Aremote-changegroup%253Dhttp%252Chttps%250Arev-branch-cache%250Astream%253Dv2&cg=1&common=0000000000000000000000000000000000000000&heads=96ee1d7354c4ad7372047672c36a1f561e3a6a4c&listkeys=phases%2Cbookmarks\r\n
   readline(-1) -> (61) x-hgproto-1: 0.1 0.2 comp=$USUAL_COMPRESSIONS$ partial-pull\r\n
   readline(-1) -> (35) accept: application/mercurial-0.1\r\n
   readline(-1) -> (2?) host: localhost:$HGPORT\r\n (glob)
   readline(-1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n
   readline(-1) -> (2) \r\n
   write(36 from 36) -> (93) HTTP/1.1 200 Script output follows\r\n
   write(23 from 23) -> (70) Server: badhttpserver\r\n
   write(37 from 37) -> (33) Date: $HTTP_DATE$\r\n
   write(33 from 41) -> (0) Content-Type: application/mercuri
   write limit reached; closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=getbundle': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
   write(36) -> HTTP/1.1 500 Internal Server Error\r\n
 
   $ rm -f error.log
 
 Server stops before it sends transfer encoding
 
   $ hg serve --config badserver.closeaftersendbytes=973 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   requesting all changes
   abort: stream ended unexpectedly (got 0 bytes, expected 1)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ tail -4 error.log
-  write(41 from 41) -> (25) Content-Type: application/mercurial-0.2\r\n
-  write(25 from 28) -> (0) Transfer-Encoding: chunke
-  write limit reached; closing socket
+  $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -4
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
   write(36) -> HTTP/1.1 500 Internal Server Error\r\n
 
   $ rm -f error.log
 
 Server sends empty HTTP body for getbundle
 
   $ hg serve --config badserver.closeaftersendbytes=978 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   requesting all changes
   abort: HTTP request error (incomplete response)
   (this may be an intermittent network failure; if the error persists, consider contacting the network or server operator)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ cat error.log
+  $ cat error.log | "$PYTHON" $TESTDIR/filtertraceback.py
   readline(65537) -> (33) GET /?cmd=capabilities HTTP/1.1\r\n
   readline(-1) -> (27) Accept-Encoding: identity\r\n
   readline(-1) -> (35) accept: application/mercurial-0.1\r\n
   readline(-1) -> (2?) host: localhost:$HGPORT\r\n (glob)
   readline(-1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n
   readline(-1) -> (2) \r\n
   write(36 from 36) -> (942) HTTP/1.1 200 Script output follows\r\n
   write(23 from 23) -> (919) Server: badhttpserver\r\n
   write(37 from 37) -> (882) Date: $HTTP_DATE$\r\n
   write(41 from 41) -> (841) Content-Type: application/mercurial-0.1\r\n
   write(21 from 21) -> (820) Content-Length: 450\r\n
   write(2 from 2) -> (818) \r\n
   write(450 from 450) -> (368) batch branchmap $USUAL_BUNDLE2_CAPS_NO_PHASES$ changegroupsubset compression=none getbundle httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx known lookup pushkey streamreqs=generaldelta,revlogv1 unbundle=HG10GZ,HG10BZ,HG10UN unbundlehash
   readline(65537) -> (26) GET /?cmd=batch HTTP/1.1\r\n
   readline(-1) -> (27) Accept-Encoding: identity\r\n
   readline(-1) -> (29) vary: X-HgArg-1,X-HgProto-1\r\n
   readline(-1) -> (41) x-hgarg-1: cmds=heads+%3Bknown+nodes%3D\r\n
   readline(-1) -> (61) x-hgproto-1: 0.1 0.2 comp=$USUAL_COMPRESSIONS$ partial-pull\r\n
   readline(-1) -> (35) accept: application/mercurial-0.1\r\n
   readline(-1) -> (2?) host: localhost:$HGPORT\r\n (glob)
   readline(-1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n
   readline(-1) -> (2) \r\n
   write(36 from 36) -> (332) HTTP/1.1 200 Script output follows\r\n
   write(23 from 23) -> (309) Server: badhttpserver\r\n
   write(37 from 37) -> (272) Date: $HTTP_DATE$\r\n
   write(41 from 41) -> (231) Content-Type: application/mercurial-0.1\r\n
   write(20 from 20) -> (211) Content-Length: 42\r\n
   write(2 from 2) -> (209) \r\n
   write(42 from 42) -> (167) 96ee1d7354c4ad7372047672c36a1f561e3a6a4c\n;
   readline(65537) -> (30) GET /?cmd=getbundle HTTP/1.1\r\n
   readline(-1) -> (27) Accept-Encoding: identity\r\n
   readline(-1) -> (29) vary: X-HgArg-1,X-HgProto-1\r\n
   readline(-1) -> (461) x-hgarg-1: bookmarks=1&bundlecaps=HG20%2Cbundle2%3DHG20%250Abookmarks%250Achangegroup%253D01%252C02%250Adigests%253Dmd5%252Csha1%252Csha512%250Aerror%253Dabort%252Cunsupportedcontent%252Cpushraced%252Cpushkey%250Ahgtagsfnodes%250Alistkeys%250Apushkey%250Aremote-changegroup%253Dhttp%252Chttps%250Arev-branch-cache%250Astream%253Dv2&cg=1&common=0000000000000000000000000000000000000000&heads=96ee1d7354c4ad7372047672c36a1f561e3a6a4c&listkeys=phases%2Cbookmarks\r\n
   readline(-1) -> (61) x-hgproto-1: 0.1 0.2 comp=$USUAL_COMPRESSIONS$ partial-pull\r\n
   readline(-1) -> (35) accept: application/mercurial-0.1\r\n
   readline(-1) -> (2?) host: localhost:$HGPORT\r\n (glob)
   readline(-1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n
   readline(-1) -> (2) \r\n
   write(36 from 36) -> (131) HTTP/1.1 200 Script output follows\r\n
   write(23 from 23) -> (108) Server: badhttpserver\r\n
   write(37 from 37) -> (71) Date: $HTTP_DATE$\r\n
   write(41 from 41) -> (30) Content-Type: application/mercurial-0.2\r\n
   write(28 from 28) -> (2) Transfer-Encoding: chunked\r\n
   write(2 from 2) -> (0) \r\n
   write limit reached; closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=getbundle': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
   write(36) -> HTTP/1.1 500 Internal Server Error\r\n
 
   $ rm -f error.log
 
 Server sends partial compression string
 
   $ hg serve --config badserver.closeaftersendbytes=1002 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   requesting all changes
   abort: HTTP request error (incomplete response)
   (this may be an intermittent network failure; if the error persists, consider contacting the network or server operator)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ cat error.log
+  $ cat error.log | "$PYTHON" $TESTDIR/filtertraceback.py
   readline(65537) -> (33) GET /?cmd=capabilities HTTP/1.1\r\n
   readline(-1) -> (27) Accept-Encoding: identity\r\n
   readline(-1) -> (35) accept: application/mercurial-0.1\r\n
   readline(-1) -> (2?) host: localhost:$HGPORT\r\n (glob)
   readline(-1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n
   readline(-1) -> (2) \r\n
   write(36 from 36) -> (966) HTTP/1.1 200 Script output follows\r\n
   write(23 from 23) -> (943) Server: badhttpserver\r\n
   write(37 from 37) -> (906) Date: $HTTP_DATE$\r\n
   write(41 from 41) -> (865) Content-Type: application/mercurial-0.1\r\n
   write(21 from 21) -> (844) Content-Length: 450\r\n
   write(2 from 2) -> (842) \r\n
   write(450 from 450) -> (392) batch branchmap $USUAL_BUNDLE2_CAPS_NO_PHASES$ changegroupsubset compression=none getbundle httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx known lookup pushkey streamreqs=generaldelta,revlogv1 unbundle=HG10GZ,HG10BZ,HG10UN unbundlehash
   readline(65537) -> (26) GET /?cmd=batch HTTP/1.1\r\n
   readline(-1) -> (27) Accept-Encoding: identity\r\n
   readline(-1) -> (29) vary: X-HgArg-1,X-HgProto-1\r\n
   readline(-1) -> (41) x-hgarg-1: cmds=heads+%3Bknown+nodes%3D\r\n
   readline(-1) -> (61) x-hgproto-1: 0.1 0.2 comp=$USUAL_COMPRESSIONS$ partial-pull\r\n
   readline(-1) -> (35) accept: application/mercurial-0.1\r\n
   readline(-1) -> (2?) host: localhost:$HGPORT\r\n (glob)
   readline(-1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n
   readline(-1) -> (2) \r\n
   write(36 from 36) -> (356) HTTP/1.1 200 Script output follows\r\n
   write(23 from 23) -> (333) Server: badhttpserver\r\n
   write(37 from 37) -> (296) Date: $HTTP_DATE$\r\n
   write(41 from 41) -> (255) Content-Type: application/mercurial-0.1\r\n
   write(20 from 20) -> (235) Content-Length: 42\r\n
   write(2 from 2) -> (233) \r\n
   write(42 from 42) -> (191) 96ee1d7354c4ad7372047672c36a1f561e3a6a4c\n;
   readline(65537) -> (30) GET /?cmd=getbundle HTTP/1.1\r\n
   readline(-1) -> (27) Accept-Encoding: identity\r\n
   readline(-1) -> (29) vary: X-HgArg-1,X-HgProto-1\r\n
   readline(-1) -> (461) x-hgarg-1: bookmarks=1&bundlecaps=HG20%2Cbundle2%3DHG20%250Abookmarks%250Achangegroup%253D01%252C02%250Adigests%253Dmd5%252Csha1%252Csha512%250Aerror%253Dabort%252Cunsupportedcontent%252Cpushraced%252Cpushkey%250Ahgtagsfnodes%250Alistkeys%250Apushkey%250Aremote-changegroup%253Dhttp%252Chttps%250Arev-branch-cache%250Astream%253Dv2&cg=1&common=0000000000000000000000000000000000000000&heads=96ee1d7354c4ad7372047672c36a1f561e3a6a4c&listkeys=phases%2Cbookmarks\r\n
   readline(-1) -> (61) x-hgproto-1: 0.1 0.2 comp=$USUAL_COMPRESSIONS$ partial-pull\r\n
   readline(-1) -> (35) accept: application/mercurial-0.1\r\n
   readline(-1) -> (2?) host: localhost:$HGPORT\r\n (glob)
   readline(-1) -> (49) user-agent: mercurial/proto-1.0 (Mercurial 4.2)\r\n
   readline(-1) -> (2) \r\n
   write(36 from 36) -> (155) HTTP/1.1 200 Script output follows\r\n
   write(23 from 23) -> (132) Server: badhttpserver\r\n
   write(37 from 37) -> (95) Date: $HTTP_DATE$\r\n
   write(41 from 41) -> (54) Content-Type: application/mercurial-0.2\r\n
   write(28 from 28) -> (26) Transfer-Encoding: chunked\r\n
   write(2 from 2) -> (24) \r\n
   write(6 from 6) -> (18) 1\\r\\n\x04\\r\\n (esc)
   write(9 from 9) -> (9) 4\r\nnone\r\n
   write(9 from 9) -> (0) 4\r\nHG20\r\n
   write limit reached; closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=getbundle': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
   write(27) -> 15\r\nInternal Server Error\r\n
 
   $ rm -f error.log
 
 Server sends partial bundle2 header magic
 
   $ hg serve --config badserver.closeaftersendbytes=999 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   requesting all changes
   abort: HTTP request error (incomplete response; expected 4 bytes got 3)
   (this may be an intermittent network failure; if the error persists, consider contacting the network or server operator)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ tail -7 error.log
+  $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -11
   write(28 from 28) -> (23) Transfer-Encoding: chunked\r\n
   write(2 from 2) -> (21) \r\n
   write(6 from 6) -> (15) 1\\r\\n\x04\\r\\n (esc)
   write(9 from 9) -> (6) 4\r\nnone\r\n
   write(6 from 9) -> (0) 4\r\nHG2
   write limit reached; closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=getbundle': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
   write(27) -> 15\r\nInternal Server Error\r\n
 
   $ rm -f error.log
 
 Server sends incomplete bundle2 stream params length
 
   $ hg serve --config badserver.closeaftersendbytes=1008 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   requesting all changes
   abort: HTTP request error (incomplete response; expected 4 bytes got 3)
   (this may be an intermittent network failure; if the error persists, consider contacting the network or server operator)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ tail -8 error.log
+  $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -12
   write(28 from 28) -> (32) Transfer-Encoding: chunked\r\n
   write(2 from 2) -> (30) \r\n
   write(6 from 6) -> (24) 1\\r\\n\x04\\r\\n (esc)
   write(9 from 9) -> (15) 4\r\nnone\r\n
   write(9 from 9) -> (6) 4\r\nHG20\r\n
   write(6 from 9) -> (0) 4\\r\\n\x00\x00\x00 (esc)
   write limit reached; closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=getbundle': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
   write(27) -> 15\r\nInternal Server Error\r\n
 
   $ rm -f error.log
 
 Servers stops after bundle2 stream params header
 
   $ hg serve --config badserver.closeaftersendbytes=1011 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   requesting all changes
   abort: HTTP request error (incomplete response)
   (this may be an intermittent network failure; if the error persists, consider contacting the network or server operator)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ tail -8 error.log
+  $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -12
   write(28 from 28) -> (35) Transfer-Encoding: chunked\r\n
   write(2 from 2) -> (33) \r\n
   write(6 from 6) -> (27) 1\\r\\n\x04\\r\\n (esc)
   write(9 from 9) -> (18) 4\r\nnone\r\n
   write(9 from 9) -> (9) 4\r\nHG20\r\n
   write(9 from 9) -> (0) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write limit reached; closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=getbundle': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
   write(27) -> 15\r\nInternal Server Error\r\n
 
   $ rm -f error.log
 
 Server stops sending after bundle2 part header length
 
   $ hg serve --config badserver.closeaftersendbytes=1020 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   requesting all changes
   abort: HTTP request error (incomplete response)
   (this may be an intermittent network failure; if the error persists, consider contacting the network or server operator)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ tail -9 error.log
+  $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -13
   write(28 from 28) -> (44) Transfer-Encoding: chunked\r\n
   write(2 from 2) -> (42) \r\n
   write(6 from 6) -> (36) 1\\r\\n\x04\\r\\n (esc)
   write(9 from 9) -> (27) 4\r\nnone\r\n
   write(9 from 9) -> (18) 4\r\nHG20\r\n
   write(9 from 9) -> (9) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (0) 4\\r\\n\x00\x00\x00)\\r\\n (esc)
   write limit reached; closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=getbundle': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
   write(27) -> 15\r\nInternal Server Error\r\n
 
   $ rm -f error.log
 
 Server stops sending after bundle2 part header
 
   $ hg serve --config badserver.closeaftersendbytes=1067 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   requesting all changes
   adding changesets
   transaction abort!
   rollback completed
   abort: HTTP request error (incomplete response)
   (this may be an intermittent network failure; if the error persists, consider contacting the network or server operator)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ tail -10 error.log
+  $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -14
   write(28 from 28) -> (91) Transfer-Encoding: chunked\r\n
   write(2 from 2) -> (89) \r\n
   write(6 from 6) -> (83) 1\\r\\n\x04\\r\\n (esc)
   write(9 from 9) -> (74) 4\r\nnone\r\n
   write(9 from 9) -> (65) 4\r\nHG20\r\n
   write(9 from 9) -> (56) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (47) 4\\r\\n\x00\x00\x00)\\r\\n (esc)
   write(47 from 47) -> (0) 29\\r\\n\x0bCHANGEGROUP\x00\x00\x00\x00\x01\x01\x07\x02	\x01version02nbchanges1\\r\\n (esc)
   write limit reached; closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=getbundle': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
   write(27) -> 15\r\nInternal Server Error\r\n
 
   $ rm -f error.log
 
 Server stops after bundle2 part payload chunk size
 
   $ hg serve --config badserver.closeaftersendbytes=1088 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   requesting all changes
   adding changesets
   transaction abort!
   rollback completed
   abort: HTTP request error (incomplete response; expected 466 bytes got 7)
   (this may be an intermittent network failure; if the error persists, consider contacting the network or server operator)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ tail -11 error.log
+  $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -15
   write(2 from 2) -> (110) \r\n
   write(6 from 6) -> (104) 1\\r\\n\x04\\r\\n (esc)
   write(9 from 9) -> (95) 4\r\nnone\r\n
   write(9 from 9) -> (86) 4\r\nHG20\r\n
   write(9 from 9) -> (77) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (68) 4\\r\\n\x00\x00\x00)\\r\\n (esc)
   write(47 from 47) -> (21) 29\\r\\n\x0bCHANGEGROUP\x00\x00\x00\x00\x01\x01\x07\x02	\x01version02nbchanges1\\r\\n (esc)
   write(9 from 9) -> (12) 4\\r\\n\x00\x00\x01\xd2\\r\\n (esc)
   write(12 from 473) -> (0) 1d2\\r\\n\x00\x00\x00\xb2\x96\xee\x1d (esc)
   write limit reached; closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=getbundle': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
   write(27) -> 15\r\nInternal Server Error\r\n
 
   $ rm -f error.log
 
 Server stops sending in middle of bundle2 payload chunk
 
   $ hg serve --config badserver.closeaftersendbytes=1549 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   requesting all changes
   adding changesets
   transaction abort!
   rollback completed
   abort: HTTP request error (incomplete response)
   (this may be an intermittent network failure; if the error persists, consider contacting the network or server operator)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ tail -12 error.log
+  $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -16
   write(28 from 28) -> (573) Transfer-Encoding: chunked\r\n
   write(2 from 2) -> (571) \r\n
   write(6 from 6) -> (565) 1\\r\\n\x04\\r\\n (esc)
   write(9 from 9) -> (556) 4\r\nnone\r\n
   write(9 from 9) -> (547) 4\r\nHG20\r\n
   write(9 from 9) -> (538) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (529) 4\\r\\n\x00\x00\x00)\\r\\n (esc)
   write(47 from 47) -> (482) 29\\r\\n\x0bCHANGEGROUP\x00\x00\x00\x00\x01\x01\x07\x02	\x01version02nbchanges1\\r\\n (esc)
   write(9 from 9) -> (473) 4\\r\\n\x00\x00\x01\xd2\\r\\n (esc)
   write(473 from 473) -> (0) 1d2\\r\\n\x00\x00\x00\xb2\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00>6a3df4de388f3c4f8e28f4f9a814299a3cbb5f50\\ntest\\n0 0\\nfoo\\n\\ninitial\x00\x00\x00\x00\x00\x00\x00\xa1j=\xf4\xde8\x8f<O\x8e(\xf4\xf9\xa8\x14)\x9a<\xbb_P\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00-foo\x00b80de5d138758541c5f05265ad144ab9fa86d1db\\n\x00\x00\x00\x00\x00\x00\x00\x07foo\x00\x00\x00h\xb8\\r\xe5\xd18u\x85A\xc5\xf0Re\xad\x14J\xb9\xfa\x86\xd1\xdb\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\x00\x00\x00\x00\x00\x00\x00\x00\\r\\n (esc)
   write limit reached; closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=getbundle': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
   write(27) -> 15\r\nInternal Server Error\r\n
 
   $ rm -f error.log
 
 Server stops sending after 0 length payload chunk size
 
   $ hg serve --config badserver.closeaftersendbytes=1580 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   requesting all changes
   adding changesets
   adding manifests
   adding file changes
   added 1 changesets with 1 changes to 1 files
   transaction abort!
   rollback completed
   abort: HTTP request error (incomplete response; expected 32 bytes got 9)
   (this may be an intermittent network failure; if the error persists, consider contacting the network or server operator)
   [255]
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ tail -13 error.log
+  $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -17
   write(6 from 6) -> (596) 1\\r\\n\x04\\r\\n (esc)
   write(9 from 9) -> (587) 4\r\nnone\r\n
   write(9 from 9) -> (578) 4\r\nHG20\r\n
   write(9 from 9) -> (569) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (560) 4\\r\\n\x00\x00\x00)\\r\\n (esc)
   write(47 from 47) -> (513) 29\\r\\n\x0bCHANGEGROUP\x00\x00\x00\x00\x01\x01\x07\x02	\x01version02nbchanges1\\r\\n (esc)
   write(9 from 9) -> (504) 4\\r\\n\x00\x00\x01\xd2\\r\\n (esc)
   write(473 from 473) -> (31) 1d2\\r\\n\x00\x00\x00\xb2\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00>6a3df4de388f3c4f8e28f4f9a814299a3cbb5f50\\ntest\\n0 0\\nfoo\\n\\ninitial\x00\x00\x00\x00\x00\x00\x00\xa1j=\xf4\xde8\x8f<O\x8e(\xf4\xf9\xa8\x14)\x9a<\xbb_P\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00-foo\x00b80de5d138758541c5f05265ad144ab9fa86d1db\\n\x00\x00\x00\x00\x00\x00\x00\x07foo\x00\x00\x00h\xb8\\r\xe5\xd18u\x85A\xc5\xf0Re\xad\x14J\xb9\xfa\x86\xd1\xdb\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\x00\x00\x00\x00\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (22) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (13) 4\\r\\n\x00\x00\x00 \\r\\n (esc)
   write(13 from 38) -> (0) 20\\r\\n\x08LISTKEYS (esc)
   write limit reached; closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=getbundle': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
   write(27) -> 15\r\nInternal Server Error\r\n
 
   $ rm -f error.log
 
 Server stops sending after 0 part bundle part header (indicating end of bundle2 payload)
 This is before the 0 size chunked transfer part that signals end of HTTP response.
 
 #  $ hg serve --config badserver.closeaftersendbytes=1755 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ hg serve --config badserver.closeaftersendbytes=1862 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   requesting all changes
   adding changesets
   adding manifests
   adding file changes
   added 1 changesets with 1 changes to 1 files
   new changesets 96ee1d7354c4
   updating to branch default
   1 files updated, 0 files merged, 0 files removed, 0 files unresolved
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ tail -22 error.log
+  $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -26
   write(9 from 9) -> (851) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (842) 4\\r\\n\x00\x00\x00)\\r\\n (esc)
   write(47 from 47) -> (795) 29\\r\\n\x0bCHANGEGROUP\x00\x00\x00\x00\x01\x01\x07\x02	\x01version02nbchanges1\\r\\n (esc)
   write(9 from 9) -> (786) 4\\r\\n\x00\x00\x01\xd2\\r\\n (esc)
   write(473 from 473) -> (313) 1d2\\r\\n\x00\x00\x00\xb2\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00>6a3df4de388f3c4f8e28f4f9a814299a3cbb5f50\\ntest\\n0 0\\nfoo\\n\\ninitial\x00\x00\x00\x00\x00\x00\x00\xa1j=\xf4\xde8\x8f<O\x8e(\xf4\xf9\xa8\x14)\x9a<\xbb_P\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00-foo\x00b80de5d138758541c5f05265ad144ab9fa86d1db\\n\x00\x00\x00\x00\x00\x00\x00\x07foo\x00\x00\x00h\xb8\\r\xe5\xd18u\x85A\xc5\xf0Re\xad\x14J\xb9\xfa\x86\xd1\xdb\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\x00\x00\x00\x00\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (304) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (295) 4\\r\\n\x00\x00\x00 \\r\\n (esc)
   write(38 from 38) -> (257) 20\\r\\n\x08LISTKEYS\x00\x00\x00\x01\x01\x00	\x06namespacephases\\r\\n (esc)
   write(9 from 9) -> (248) 4\\r\\n\x00\x00\x00:\\r\\n (esc)
   write(64 from 64) -> (184) 3a\r\n96ee1d7354c4ad7372047672c36a1f561e3a6a4c	1\npublishing	True\r\n
   write(9 from 9) -> (175) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (166) 4\\r\\n\x00\x00\x00#\\r\\n (esc)
   write(41 from 41) -> (125) 23\\r\\n\x08LISTKEYS\x00\x00\x00\x02\x01\x00		namespacebookmarks\\r\\n (esc)
   write(9 from 9) -> (116) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (107) 4\\r\\n\x00\x00\x00\x1d\\r\\n (esc)
   write(35 from 35) -> (72) 1d\\r\\n\x16cache:rev-branch-cache\x00\x00\x00\x03\x00\x00\\r\\n (esc)
   write(9 from 9) -> (63) 4\\r\\n\x00\x00\x00'\\r\\n (esc)
   write(45 from 45) -> (18) 27\\r\\n\x00\x00\x00\x07\x00\x00\x00\x01\x00\x00\x00\x00default\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\\r\\n (esc)
   write(9 from 9) -> (9) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (0) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write limit reached; closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=getbundle': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
   write(27) -> 15\r\nInternal Server Error\r\n
 
   $ rm -f error.log
   $ rm -rf clone
 
 Server sends a size 0 chunked-transfer size without terminating \r\n
 
   $ hg serve --config badserver.closeaftersendbytes=1865 -p $HGPORT -d --pid-file=hg.pid -E error.log
   $ cat hg.pid > $DAEMON_PIDS
 
   $ hg clone http://localhost:$HGPORT/ clone
   requesting all changes
   adding changesets
   adding manifests
   adding file changes
   added 1 changesets with 1 changes to 1 files
   new changesets 96ee1d7354c4
   updating to branch default
   1 files updated, 0 files merged, 0 files removed, 0 files unresolved
 
   $ killdaemons.py $DAEMON_PIDS
 
-  $ tail -23 error.log
+  $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -27
   write(9 from 9) -> (854) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (845) 4\\r\\n\x00\x00\x00)\\r\\n (esc)
   write(47 from 47) -> (798) 29\\r\\n\x0bCHANGEGROUP\x00\x00\x00\x00\x01\x01\x07\x02	\x01version02nbchanges1\\r\\n (esc)
   write(9 from 9) -> (789) 4\\r\\n\x00\x00\x01\xd2\\r\\n (esc)
   write(473 from 473) -> (316) 1d2\\r\\n\x00\x00\x00\xb2\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00>6a3df4de388f3c4f8e28f4f9a814299a3cbb5f50\\ntest\\n0 0\\nfoo\\n\\ninitial\x00\x00\x00\x00\x00\x00\x00\xa1j=\xf4\xde8\x8f<O\x8e(\xf4\xf9\xa8\x14)\x9a<\xbb_P\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00-foo\x00b80de5d138758541c5f05265ad144ab9fa86d1db\\n\x00\x00\x00\x00\x00\x00\x00\x07foo\x00\x00\x00h\xb8\\r\xe5\xd18u\x85A\xc5\xf0Re\xad\x14J\xb9\xfa\x86\xd1\xdb\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\x00\x00\x00\x00\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (307) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (298) 4\\r\\n\x00\x00\x00 \\r\\n (esc)
   write(38 from 38) -> (260) 20\\r\\n\x08LISTKEYS\x00\x00\x00\x01\x01\x00	\x06namespacephases\\r\\n (esc)
   write(9 from 9) -> (251) 4\\r\\n\x00\x00\x00:\\r\\n (esc)
   write(64 from 64) -> (187) 3a\r\n96ee1d7354c4ad7372047672c36a1f561e3a6a4c	1\npublishing	True\r\n
   write(9 from 9) -> (178) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (169) 4\\r\\n\x00\x00\x00#\\r\\n (esc)
   write(41 from 41) -> (128) 23\\r\\n\x08LISTKEYS\x00\x00\x00\x02\x01\x00		namespacebookmarks\\r\\n (esc)
   write(9 from 9) -> (119) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (110) 4\\r\\n\x00\x00\x00\x1d\\r\\n (esc)
   write(35 from 35) -> (75) 1d\\r\\n\x16cache:rev-branch-cache\x00\x00\x00\x03\x00\x00\\r\\n (esc)
   write(9 from 9) -> (66) 4\\r\\n\x00\x00\x00'\\r\\n (esc)
   write(45 from 45) -> (21) 27\\r\\n\x00\x00\x00\x07\x00\x00\x00\x01\x00\x00\x00\x00default\x96\xee\x1dsT\xc4\xadsr\x04vr\xc3j\x1fV\x1e:jL\\r\\n (esc)
   write(9 from 9) -> (12) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (3) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(3 from 5) -> (0) 0\r\n
   write limit reached; closing socket
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=getbundle': (glob)
+  Traceback (most recent call last):
+  Exception: connection closed after sending N bytes
+  
   write(27) -> 15\r\nInternal Server Error\r\n
 
   $ rm -f error.log
   $ rm -rf clone