<pierre.vi...@postfinance.ch> writes:
> The status line is not blocked. The debugging message means that we
> have got an header with a null key and with the status line as value:
> in this case the header is not added to the request sent back to the
> client. This seems to be common that some HTTP Implementations return
> such a null key header in the list of headers of a request.
I've never seen Apache send a second status line. Perhaps the message
about null key applies to this mysterious line in the trace:
ch.nevis.session.secroles: auth.strong,idma_Benutzer,infplat_user,esclienttest_r
oleBC,esclienttest_roleA,esclienttest_roleB,depo_Admin,itam_Leser,itam_Administr
ator,itsms_asset_viewer,itsms_svc_req_usr,testsaml_admin,global.allow,acc.idma,a
cc.infplat,acc.esclienttest,acc.depo,acc.itam,acc.itsms,acc.testsaml
I see that every response also has:
Connection: close
This looks as if you do not have KeepAlive enabled on the server, or
perhaps the proxy does not support pipelining. That is going to result
in poor performance for clients that use serf.
All the above is probably irrelevant to the problem.
I've converted your trace into a Python script to implement a server
that behaves like yours. The first, larger, OPTIONS response is a
typical response from a server that supports Subversion's v2 protocol.
The second, smaller, OPTIONS response is the client probing to see if
chunked transfer encoding is upported. All the subsequent PROPFINDS are
v1 protocol and this is where it gets tricky.
Using a standard 1.8 client against this dummy server gives:
$ svn ls http://127.0.0.1:7777/svn/t_sponis_testrepo
svn: E175009: XML Parsing failed: Unexpected root element 'multistatus'
That's because the client sends v2 requests and the v1 responses do not
match. Now I have a debug client and I can force v1 using
$ SVN_I_LIKE_LATENCY_SO_IGNORE_HTTPV2=yes svn ls
http://127.0.0.1:7777/svn/t_sponis_testrepo
branches/
tags/
trunk/
Your client will not have the debug code to do that. How is your client
switching to the v1 protocol? Either your proxy is not forwarding the
SVN-Me-Resource header or your client is patched to ignore v2, which
ever it is your environment is non-standard. How does your client
respond when run against this dummy server? (You must restart the dummy
server after a client fail so that responses match the requests.)
#!/usr/bin/python
import SocketServer
import re
class MyTCPHandler(SocketServer.StreamRequestHandler):
responses = [
('HTTP/1.1 200 OK\r\n'
'SVN-Repository-MergeInfo: yes\r\n'
'SVN-Allow-Bulk-Updates: On\r\n'
'SVN-Rev-Root-Stub: /svn/t_sponis_testrepo/!svn/rvr\r\n'
'Content-Length: 201\r\n'
'SVN-Txn-Root-Stub: /svn/t_sponis_testrepo/!svn/txr\r\n'
'SVN-VTxn-Root-Stub: /svn/t_sponis_testrepo/!svn/vtxr\r\n'
'SVN-Repository-UUID: 0926ec5e-c495-11e3-b81a-bb1aca739395\r\n'
'Connection: close\r\n'
'Server: Apache\r\n'
'DAV: 1,2, version-control,checkout,working-resource, merge,baseline,activity,version-controlled-collection, http://subversion.tigris.org/xmlns/dav/svn/depth, http://subversion.tigris.org/xmlns/dav/svn/log-revprops, http://subversion.tigris.org/xmlns/dav/svn/atomic-revprops, http://subversion.tigris.org/xmlns/dav/svn/partial-replay, http://subversion.tigris.org/xmlns/dav/svn/inherited-props, http://subversion.tigris.org/xmlns/dav/svn/inline-props, http://subversion.tigris.org/xmlns/dav/svn/reverse-file-revs, http://subversion.tigris.org/xmlns/dav/svn/mergeinfo, http://subversion.tigris.org/xmlns/dav/svn/ephemeral-txnprops, http://subversion.tigris.org/xmlns/dav/svn/replay-rev-resource\r\n'
'SVN-VTxn-Stub: /svn/t_sponis_testrepo/!svn/vtxn\r\n'
'SVN-Rev-Stub: /svn/t_sponis_testrepo/!svn/rev\r\n'
'MS-Author-Via: DAV\r\n'
'SVN-Me-Resource: /svn/t_sponis_testrepo/!svn/me\r\n'
'Date: Tue, 06 Jan 2015 14:43:25 GMT\r\n'
'SVN-Txn-Stub: /svn/t_sponis_testrepo/!svn/txn\r\n'
'Allow: OPTIONS,GET,HEAD,POST,DELETE,TRACE,PROPFIND,PROPPATCH,COPY,MOVE,LOCK,UNLOCK,CHECKOUT\r\n'
'SVN-Repository-Root: /svn/t_sponis_testrepo\r\n'
'SVN-Supported-Posts: create-txn, create-txn-with-props\r\n'
'Content-Type: text/xml; charset="utf-8\r\n'
'SVN-Youngest-Rev: 16\r\n'
'\r\n'
'<?xml version="1.0" encoding="utf-8"?>\n'
'<D:options-response xmlns:D="DAV:">\n'
'<D:activity-collection-set><D:href>/svn/t_sponis_testrepo/!svn/act/</D:href></D:activity-collection-set></D:options-response>\n'
),
('HTTP/1.1 200 OK\r\n'
'DAV: 1,2, version-control,checkout,working-resource, merge,baseline,activity,version-controlled-collection, http://subversion.tigris.org/xmlns/dav/svn/depth, http://subversion.tigris.org/xmlns/dav/svn/log-revprops, http://subversion.tigris.org/xmlns/dav/svn/atomic-revprops, http://subversion.tigris.org/xmlns/dav/svn/partial-replay, http://subversion.tigris.org/xmlns/dav/svn/inherited-props, http://subversion.tigris.org/xmlns/dav/svn/inline-props, http://subversion.tigris.org/xmlns/dav/svn/reverse-file-revs, http://subversion.tigris.org/xmlns/dav/svn/mergeinfo\r\n'
'MS-Author-Via: DAV\r\n'
'Date: Tue, 06 Jan 2015 14:43:25 GMT\r\n'
'Content-Length: 97\r\n'
'Allow: OPTIONS,GET,HEAD,POST,DELETE,TRACE,PROPFIND,PROPPATCH,COPY,MOVE,LOCK,UNLOCK,CHECKOUT\r\n'
'Connection: close\r\n'
'Content-Type: text/xml; charset="utf-8\r\n'
'Server: Apache\r\n'
'\r\n'
'<?xml version="1.0" encoding="utf-8"?>\n'
'<D:options-response xmlns:D="DAV:">\n'
'</D:options-response>\n'
),
('HTTP/1.1 207 Multi-Status\r\n'
'Date: Tue, 06 Jan 2015 14:43:26 GMT\r\n'
'Content-Length: 673\r\n'
'Connection: close\r\n'
'Content-Type: text/xml; charset="utf-8"\r\n'
'Server: Apache\r\n'
'\r\n'
'<?xml version="1.0" encoding="utf-8"?>\n'
'<D:multistatus xmlns:D="DAV:" xmlns:ns1="http://subversion.tigris.org/xmlns/dav/"; xmlns:ns0="DAV:">\n'
'<D:response xmlns:lp1="DAV:" xmlns:lp2="http://subversion.tigris.org/xmlns/dav/";>\n'
'<D:href>/svn/t_sponis_testrepo/</D:href>\n'
'<D:propstat>\n'
'<D:prop>\n'
'<lp1:version-controlled-configuration><D:href>/svn/t_sponis_testrepo/!svn/vcc/default</D:href></lp1:version-controlled-configuration>\n'
'<lp1:resourcetype><D:collection/></lp1:resourcetype>\n'
'<lp2:baseline-relative-path/>\n'
'<lp2:repository-uuid>0926ec5e-c495-11e3-b81a-bb1aca739395</lp2:repository-uuid>\n'
'</D:prop>\n'
'<D:status>HTTP/1.1 200 OK</D:status>\n'
'</D:propstat>\n'
'</D:response>\n'
'</D:multistatus>\n'
),
('HTTP/1.1 207 Multi-Status\r\n'
'Date: Tue, 06 Jan 2015 14:43:26 GMT\r\n'
'Content-Length: 425\r\n'
'Connection: close\r\n'
'Content-Type: text/xml; charset="utf-8"\r\n'
'Server: Apache\r\n'
'\r\n'
'<?xml version="1.0" encoding="utf-8"?>\n'
'<D:multistatus xmlns:D="DAV:" xmlns:ns0="DAV:">\n'
'<D:response xmlns:lp1="DAV:" xmlns:lp2="http://subversion.tigris.org/xmlns/dav/";>'
'<D:href>/svn/t_sponis_testrepo/!svn/vcc/default</D:href>\n'
'<D:propstat>\n'
'<D:prop>\n'
'<lp1:checked-in><D:href>/svn/t_sponis_testrepo/!svn/bln/16</D:href></lp1:checked-in>\n'
'</D:prop>\n'
'<D:status>HTTP/1.1 200 OK</D:status>\n'
'</D:propstat>\n'
'</D:response>\n'
'</D:multistatus>\n'
'\n'
),
('HTTP/1.1 207 Multi-Status\r\n'
'Date: Tue, 06 Jan 2015 14:43:26 GMT\r\n'
'Content-Length: 478\r\n'
'Connection: close\r\n'
'Content-Type: text/xml; charset="utf-8"\r\n'
'Server: Apache\r\n'
'\r\n'
'<?xml version="1.0" encoding="utf-8"?>\n'
'<D:multistatus xmlns:D="DAV:" xmlns:ns0="DAV:">\n'
'<D:response xmlns:lp1="DAV:" xmlns:lp2="http://subversion.tigris.org/xmlns/dav/";>\n'
'<D:href>/svn/t_sponis_testrepo/!svn/bln/16</D:href>\n'
'<D:propstat>\n'
'<D:prop>\n'
'<lp1:baseline-collection><D:href>/svn/t_sponis_testrepo/!svn/bc/16/</D:href></lp1:baseline-collection>\n'
'<lp1:version-name>16</lp1:version-name>\n'
'</D:prop>\n'
'<D:status>HTTP/1.1 200 OK</D:status>\n'
'</D:propstat>\n'
'</D:response>\n'
'</D:multistatus>\n'
'\n'
),
('HTTP/1.1 207 Multi-Status\r\n'
'Date: Tue, 06 Jan 2015 14:43:27 GMT\r\n'
'Content-Length: 775\r\n'
'Connection: close\r\n'
'Content-Type: text/xml; charset="utf-8"\r\n'
'Server: Apache\r\n'
'\r\n'
'<?xml version="1.0" encoding="utf-8"?>\n'
'<D:multistatus xmlns:D="DAV:" xmlns:ns1="http://subversion.tigris.org/xmlns/dav/"; xmlns:ns0="DAV:">\n'
'<D:response xmlns:lp1="DAV:" xmlns:lp2="http://subversion.tigris.org/xmlns/dav/"; xmlns:g0="DAV:">\n'
'<D:href>/svn/t_sponis_testrepo/!svn/bc/16/</D:href>\n'
'<D:propstat>\n'
'<D:prop>\n'
'<lp1:resourcetype><D:collection/></lp1:resourcetype>\n'
'<lp2:deadprop-count>0</lp2:deadprop-count>\n'
'<lp1:version-name>16</lp1:version-name>\n'
'<lp1:creationdate>2014-12-18T09:42:07.784066Z</lp1:creationdate>\n'
'<lp1:creator-displayname>viretp</lp1:creator-displayname>\n'
'</D:prop>\n'
'<D:status>HTTP/1.1 200 OK</D:status>\n'
'</D:propstat>\n'
'<D:propstat>\n'
'<D:prop>\n'
'<g0:getcontentlength/>\n'
'</D:prop>\n'
'<D:status>HTTP/1.1 404 Not Found</D:status>\n'
'</D:propstat>\n'
'</D:response>\n'
'</D:multistatus>\n'
'\n'
),
('HTTP/1.1 207 Multi-Status\r\n'
'Date: Tue, 06 Jan 2015 14:43:27 GMT\r\n'
'Content-Length: 1052\r\n'
'Connection: close\r\n'
'Content-Type: text/xml; charset="utf-8"\r\n'
'Server: Apache\r\n'
'\r\n'
'<?xml version="1.0" encoding="utf-8"?>\n'
'<D:multistatus xmlns:D="DAV:" xmlns:ns0="DAV:">\n'
'<D:response xmlns:lp1="DAV:">\n'
'<D:href>/svn/t_sponis_testrepo/!svn/bc/16/</D:href>\n'
'<D:propstat>\n'
'<D:prop>\n'
'<lp1:resourcetype><D:collection/></lp1:resourcetype>\n'
'</D:prop>\n'
'<D:status>HTTP/1.1 200 OK</D:status>\n'
'</D:propstat>\n'
'</D:response>\n'
'<D:response xmlns:lp1="DAV:">\n'
'<D:href>/svn/t_sponis_testrepo/!svn/bc/16/trunk/</D:href>\n'
'<D:propstat>\n'
'<D:prop>\n'
'<lp1:resourcetype><D:collection/></lp1:resourcetype>\n'
'</D:prop>\n'
'<D:status>HTTP/1.1 200 OK</D:status>\n'
'</D:propstat>\n'
'</D:response>\n'
'<D:response xmlns:lp1="DAV:">\n'
'<D:href>/svn/t_sponis_testrepo/!svn/bc/16/branches/</D:href>\n'
'<D:propstat>\n'
'<D:prop>\n'
'<lp1:resourcetype><D:collection/></lp1:resourcetype>\n'
'</D:prop>\n'
'<D:status>HTTP/1.1 200 OK</D:status>\n'
'</D:propstat>\n'
'</D:response>\n'
'<D:response xmlns:lp1="DAV:">\n'
'<D:href>/svn/t_sponis_testrepo/!svn/bc/16/tags/</D:href>\n'
'<D:propstat>\n'
'<D:prop>\n'
'<lp1:resourcetype><D:collection/></lp1:resourcetype>\n'
'</D:prop>\n'
'<D:status>HTTP/1.1 200 OK</D:status>\n'
'</D:propstat>\n'
'</D:response>\n'
'</D:multistatus>\n'
'\n'
),
]
response = 0
def handle(self):
clen = None
chunked = False
while True:
self.data = self.rfile.readline().strip()
print "read: " + self.data
if self.data == "Transfer-Encoding: chunked":
chunked = True
m = re.match('Content-Length: (.*)', self.data)
if m:
clen = int(m.group(1))
if self.data == '':
break
if chunked: # Handling one chunk is enough for now
self.data = self.rfile.readline().strip()
print "read: " + self.data
clen = int(self.data, 16)
if clen:
self.data = self.rfile.read(clen)
print "read: " + self.data
if chunked:
self.data = self.rfile.readline().strip()
self.data = self.rfile.readline().strip()
print "read: " + self.data
self.wfile.write(MyTCPHandler.responses[MyTCPHandler.response])
MyTCPHandler.response += 1
if MyTCPHandler.response == 7:
MyTCPHandler.response = 0
if __name__ == "__main__":
SocketServer.TCPServer.allow_reuse_address = True
server = SocketServer.TCPServer(("localhost", 7777), MyTCPHandler)
server.serve_forever()
--
Philip Martin | Subversion Committer
WANdisco // *Non-Stop Data*
