E130003: The XML response contains invalid XML - svn co and log issue on some repos using https/http
NOCERA, ANDY
Hi,
I have a recently built SVN 1.9.7 including httpd and I see issues using https/https protocol on a few repos and version. The test repos are 1.8.X and work using file level protocol and svnserve. Some Other repos work with no issues.
For asgard example below, I was able to checkout from -r r1114 having latest r1115 checkout fail. I was able to checkout 1114 and commit to 1116, however that didn’t fix it, Svnadmin verify returns no errors.
Please advise,
Andy
svn co https://xxx.com:6022/svn/asgard
svn: E130003: The XML response contains invalid XML
svn -v -rr1014 log https://xxxx.com:6022/svn/asgard
------------------------------------------------------------------------
r1014 | asgardia | 2015-05-08 16:05:07 -0700 (Fri, 08 May 2015) | 1 line
Changed paths:
A /stash
stuff
------------------------------------------------------------------------
svn -v -rr1015 log https://xxx.com:6022/svn/asgard
svn: E175002: Unexpected HTTP status 400 'Bad Request' on '/svn/asgard/!svn/rvr/1015'
svn: E160062: Additional errors:
svn: E160062: Malformed node revision ID string
$ svn log -V -r r1116 file:///opt/app/scm/svn/reps/asgard
svn: invalid option character: V
Type 'svn help' for usage.
$ svn log -v -r r1116 file:///opt/app/scm/svn/reps/asgard
------------------------------------------------------------------------
r1116 | an2124 | 2018-02-27 16:54:13 -0500 (Tue, 27 Feb 2018) | 2 lines
Changed paths:
A /x
[TEST] This is a test commit to remove 1015
------------------------------------------------------------------------
$ svn log -v -r r1115 file:///opt/app/scm/svn/reps/asgard
------------------------------------------------------------------------
r1115 | rv620d | 2016-07-20 11:26:45 -0400 (Wed, 20 Jul 2016) | 1 line
Changed paths:
M /almighty-gab/test_file_gabalmighty.dat
test
------------------------------------------------------------------------
$ svn log -v -r r1114 file:///opt/app/scm/svn/reps/asgard
------------------------------------------------------------------------
r1114 | grageda | 2016-06-08 16:00:14 -0400 (Wed, 08 Jun 2016) | 1 line
Changed paths:
M /developer1/test.sh
COMMIT
------------------------------------------------------------------------
#apr-1.6.3.tar - standard apache
#apr-util-1.6.1.tar - standard apache utils
#pcre-8.41.tar - used by httpd
#libtool-2.4.6.tar - used by openldap
#openldap_2_4_26_src.tar - needed for httpd+ldap and svn+https
# openldap_2_4_26_src.tar - contains 02-berkeleydb 03-sasl2 – we didn’t need to build.
#
#Python-2.7.13.tar - used to build scons and serf
# scons-local-2.3.0.tar - build script for serf
# serf-1.3.9.zip - enabes SVN https://svn....com
#subversion-1.9.7.tar - subversion distribution
# subversion-1.9.7/sqlite-amalgamation - had to be added
# httpd-2.4.29.tar - httpd - standalone https
Paul Hammant
NOCERA, ANDY
Paul,
Here is the information regarding the logs,
Thanks
Andy
CMD:
svn: E130003: The XML response contains invalid XML
ERROR LOG
[Tue Feb 27 21:31:25.717954 2018] [ssl:info] [pid 18302:tid 140359493441280] [client IPADDRESS:55820] AH01964: Connection to child 139 established (server xxxxx.com:443)
[Tue Feb 27 21:31:25.932500 2018] [authz_svn:info] [pid 18302:tid 140359482951424] [client IPADDRESS:55820] Access granted: 'an2124' OPTIONS asgard:/
[Tue Feb 27 21:31:25.989989 2018] [authz_svn:info] [pid 18302:tid 140359461971712] [client IPADDRESS:55820] Access granted: 'an2124' OPTIONS asgard:/
[Tue Feb 27 21:31:26.045795 2018] [authz_svn:info] [pid 18302:tid 140359472461568] [client IPADDRESS:55820] Access granted: 'an2124' OPTIONS asgard:/
[Tue Feb 27 21:31:26.101858 2018] [authz_svn:info] [pid 18302:tid 140359451481856] [client IPADDRESS:55820] Access granted: 'an2124' PROPFIND asgard:/
[Tue Feb 27 21:31:26.157470 2018] [ssl:info] [pid 18302:tid 140359577360128] (70014)End of file found: [client IPADDRESS:55820] AH01991: SSL input filter read failed.
[Tue Feb 27 21:31:26.231191 2018] [ssl:info] [pid 31885:tid 140359587849984] [client IPADDRESS:55822] AH01964: Connection to child 258 established (server scm.test.att.com:443)
[Tue Feb 27 21:31:26.434479 2018] [authz_svn:info] [pid 31885:tid 140359556380416] [client IPADDRESS:55822] Access granted: 'an2124' OPTIONS asgard:/
[Tue Feb 27 21:31:26.490891 2018] [authz_svn:info] [pid 31885:tid 140359545890560] [client IPADDRESS:55822] Access granted: 'an2124' OPTIONS asgard:/
[Tue Feb 27 21:31:26.546663 2018] [authz_svn:info] [pid 31885:tid 140359472461568] [client IPADDRESS:55822] Access granted: 'an2124' OPTIONS asgard:/
[Tue Feb 27 21:31:26.613113 2018] [authz_svn:info] [pid 31885:tid 140359420012288] [client IPADDRESS:55822] Access granted: 'an2124' REPORT asgard:
[Tue Feb 27 21:31:26.613393 2018] [authz_svn:info] [pid 31885:tid 140359420012288] [client IPADDRESS:55822] Access granted: 'an2124' GET asgard:/
[Tue Feb 27 21:31:26.613665 2018] [authz_svn:info] [pid 31885:tid 140359420012288] [client IPADDRESS:55822] Access granted: 'an2124' GET asgard:/x
[Tue Feb 27 21:31:26.613800 2018] [authz_svn:info] [pid 31885:tid 140359420012288] [client IPADDRESS:55822] Access granted: 'an2124' GET asgard:/almighty-gab
[Tue Feb 27 21:31:26.614012 2018] [authz_svn:info] [pid 31885:tid 140359420012288] [client IPADDRESS:55822] Access granted: 'an2124' GET asgard:/almighty-gab/test_file_gabalmighty.dat
[Tue Feb 27 21:31:26.614221 2018] [dav:error] [pid 31885:tid 140359420012288] [client IPADDRESS:55822] Provider encountered an error while streaming a REPORT response. [500, #0]
[Tue Feb 27 21:31:26.614236 2018] [dav:error] [pid 31885:tid 140359420012288] [client IPADDRESS:55822] A failure occurred while driving the update report editor [500, #160053]
[Tue Feb 27 21:31:26.614242 2018] [dav:error] [pid 31885:tid 140359420012288] [client IPADDRESS:55822] While reading representation offsets for node-revision '2-1026.0.r1115/37': [500, #160053]
[Tue Feb 27 21:31:26.614248 2018] [dav:error] [pid 31885:tid 140359420012288] [client IPADDRESS:55822] malformed txn id '1114-99a9211d96cf5c6c693c519a16016f97ab2324bcwn' [500, #160053]
Server version: Apache/2.4.29 (Unix)
Server built: Feb 26 2018 12:21:35
$ bin/httpd -V
Server version: Apache/2.4.29 (Unix)
Server built: Feb 26 2018 12:21:35
Server's Module Magic Number: 20120211:68
Server loaded: APR 1.6.3, APR-UTIL 1.6.1
Compiled using: APR 1.6.3, APR-UTIL 1.6.1
Architecture: 64-bit
Server MPM: event
threaded: yes (fixed thread count)
forked: yes (variable process count)
Server compiled with....
-D APR_HAS_SENDFILE
-D APR_HAS_MMAP
-D APR_HAVE_IPV6 (IPv4-mapped addresses enabled)
-D APR_USE_SYSVSEM_SERIALIZE
-D APR_USE_PTHREAD_SERIALIZE
-D SINGLE_LISTEN_UNSERIALIZED_ACCEPT
-D APR_HAS_OTHER_CHILD
-D AP_HAVE_RELIABLE_PIPED_LOGS
-D DYNAMIC_MODULE_LIMIT=256
-D HTTPD_ROOT="/opt/app/scm/svn/binaries/svn_1.9.7"
-D SUEXEC_BIN="/opt/app/scm/svn/binaries/svn_1.9.7/bin/suexec"
-D DEFAULT_PIDLOG="logs/httpd.pid"
-D DEFAULT_SCOREBOARD="logs/apache_runtime_status"
-D DEFAULT_ERRORLOG="logs/error_log"
-D AP_TYPES_CONFIG_FILE="conf/mime.types"
-D SERVER_CONFIG_FILE="conf/httpd.conf"
Paul Hammant
Michael Rohan
Do you get the same error with a testfile.txt resource in a freshly created (and Apache mounted) Subversion repo?
Michael Rohan
Stone Pillar Technologies
=========================
NOCERA, ANDY
There are several repos work fine and even different version is this repo.
From: Paul Hammant [mailto:pa...@hammant.org]
Sent: Tuesday, February 27, 2018 9:44 PM
To: NOCERA, ANDY <an2...@att.com>
Cc: us...@subversion.apache.org
Subject: Re: E130003: The XML response contains invalid XML - svn co and log issue on some repos using https/http
Do you get the same error with a testfile.txt resource in a freshly created (and Apache mounted) Subversion repo?
NOCERA, ANDY
My cert is not valid at this point, I had turned off ssl and had the same error. I wasn’t sure how to get beyond the 301 on a curl
curl -k -u an2124 --insecure https://scm-uat.web.att.com:6022/svn/asgard
Enter host password for user 'an2124':
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>301 Moved Permanently</title>
</head><body>
<h1>Moved Permanently</h1>
<p>The document has moved <a href="https://scm-uat.web.att.com:6022/svn/asgard/">here</a>.</p>
</body></html>
From: Michael Rohan [mailto:mro...@stonepillar.com]
Sent: Tuesday, February 27, 2018 10:11 PM
To: Paul Hammant <pa...@hammant.org>
Cc: NOCERA, ANDY <an2...@att.com>; us...@subversion.apache.org
Subject: Re: E130003: The XML response contains invalid XML - svn co and log issue on some repos using https/http
Hi,
Michael.
Andreas Krey
> My cert is not valid at this point, I had turned off ssl and had the same error. I wasn???t sure how to get beyond the 301 on a curl
You ask for .../asgard, and get redirected to .../asgard/ (note the slash at the end). Try that.
Andreas
--
"Totally trivial. Famous last words."
From: Linus Torvalds <torvalds@*.org>
Date: Fri, 22 Jan 2010 07:29:21 -0800
Philip Martin
> svn co https://xxx.com:6022/svn/asgard
> svn: E130003: The XML response contains invalid XML
traffic and see the failing XML:
https://subversion.apache.org/docs/community-guide/debugging.html#net-trace-socat
--
Philip
NOCERA, ANDY
svn co https://scm-uat.web.att.com:6022/svn/asgard svn: E130003: The XML response contains invalid XML
[an2124@hlth509 test3]$ svn co https://scm-uat.web.att.com:6022/svn/asgard/
svn: E130003: The XML response contains invalid XML
curl -k -u an2124 --insecure https://scm-uat.web.att.com:6022/svn/asgard/
<body>
<h2>asgard - Revision 1116: /</h2>
<ul>
<li><a href="../">..</a></li>
<li><a href=".project">.project</a></li>
<li><a href="00%20Admin/">00 Admin/</a></li>
<li><a href="10%20CSCM+SCME%20Documents/">10 CSCM+SCME Documents/</a></li>
<li><a href="20%20ARCADE%20Documents/">20 ARCADE Documents/</a></li>
<li><a href="30%20SDT/">30 SDT/</a></li>
<li><a href="40%20Regression%20Test%20Suite/">40 Regression Test Suite/</a></li>
<li><a href="70%20Miscellaneous/">70 Miscellaneous/</a></li>
<li><a href="80%20Archive/">80 Archive/</a></li>
<li><a href="90_Temp/">90_Temp/</a></li>
<li><a href="ARCADE/">ARCADE/</a></li>
<li><a href="Arcade/">Arcade/</a></li>
<li><a href="Asgard">Asgard</a></li>
<li><a href="CCM06/">CCM06/</a></li>
<li><a href="CCM06_177/">CCM06_177/</a></li>
<li><a href="Images/">Images/</a></li>
<li><a href="Kunebelles">Kunebelles</a></li>
<li><a href="Misc/">Misc/</a></li>
<li><a href="Optimizations/">Optimizations/</a></li>
<li><a href="Scripts/">Scripts/</a></li>
<li><a href="Selenium%20Stuff/">Selenium Stuff/</a></li>
<li><a href="Thumbs.db">Thumbs.db</a></li>
<li><a href="almighty-gab/">almighty-gab/</a></li>
<li><a href="almighty-only/">almighty-only/</a></li>
<li><a href="aod/">aod/</a></li>
<li><a href="ccm06_n1_1_29234/">ccm06_n1_1_29234/</a></li>
<li><a href="ccm06_n1_2_29234/">ccm06_n1_2_29234/</a></li>
<li><a href="ccm06_n1_3_29234/">ccm06_n1_3_29234/</a></li>
<li><a href="ccm06_n1_4_29234/">ccm06_n1_4_29234/</a></li>
<li><a href="ccm06_n1_5_29234/">ccm06_n1_5_29234/</a></li>
<li><a href="dev1">dev1</a></li>
<li><a href="developer1/">developer1/</a></li>
<li><a href="idemo/">idemo/</a></li>
<li><a href="logs">logs</a></li>
<li><a href="logs2">logs2</a></li>
<li><a href="logz">logz</a></li>
<li><a href="offshore/">offshore/</a></li>
<li><a href="onshore/">onshore/</a></li>
<li><a href="sonar/">sonar/</a></li>
<li><a href="stash">stash</a></li>
<li><a href="trunk/">trunk/</a></li>
<li><a href="viewvc/">viewvc/</a></li>
<li><a href="viewvc_1.1.22/">viewvc_1.1.22/</a></li>
<li><a href="x">x</a></li>
<li><a href="yeahyeah">yeahyeah</a></li>
<li><a href="~$ployment%20to%20Test.doc">~$ployment to Test.doc</a></li>
</ul>
</body></html>[an2124@hlth509 test3]$
-----Original Message-----
From: Andreas Krey [mailto:a.k...@gmx.de]
Sent: Wednesday, February 28, 2018 3:15 AM
To: NOCERA, ANDY <an2...@att.com>
Subject: Re: E130003: The XML response contains invalid XML - svn co and log issue on some repos using https/http
Paul Hammant
NOCERA, ANDY
I have seen a different result from svn log and I can cherry pick around and see some expected output.
The curl output below has… "~$ployment%20to%20Test.doc">~$ployment to Test.doc</ … Could the file with ~$ and %20 cause an issue?
svn -rr1013 log https://scm-uat.web.att.com:6022/svn/asgard
------------------------------------------------------------------------
r1013 | asgardia | 2015-05-04 15:48:15 -0700 (Mon, 04 May 2015) | 1 line
stuff
------------------------------------------------------------------------
[an2124@hlth509 test3]$ svn -rr1014 log https://scm-uat.web.att.com:6022/svn/asgard
------------------------------------------------------------------------
r1014 | asgardia | 2015-05-08 16:05:07 -0700 (Fri, 08 May 2015) | 1 line
stuff
------------------------------------------------------------------------
[an2124@hlth509 test3]$ svn -rr1015 log https://scm-uat.web.att.com:6022/svn/asgard
svn: E175002: Unexpected HTTP status 400 'Bad Request' on '/svn/asgard/!svn/rvr/1015'
svn: E160062: Additional errors:
svn: E160062: Malformed node revision ID string
Not sure how to curl and cherry pick a version but here is latest.
From: Paul Hammant [mailto:pa...@hammant.org]
Sent: Wednesday, February 28, 2018 8:28 AM
To: NOCERA, ANDY <an2...@att.com>
Cc: Andreas Krey <a.k...@gmx.de>; Michael Rohan <mro...@stonepillar.com>; us...@subversion.apache.org
Subject: Re: E130003: The XML response contains invalid XML - svn co and log issue on some repos using https/http
As you work toward a conclusion, Andy, do you think there was a different error message that could have driven you to root cause more quickly?
NOCERA, ANDY
I disabled ssl to simplify. I noticed that svn log sometimes stops with an error, sometimes it just stops although there is an error in the log. I think I need to review the build. Not sure if it’s the SVN side of the build or the httpd side.
Looks like a dav error.
[Thu Mar 01 17:42:06.060588 2018] [dav:error] [pid 116212:tid 140359367563008] [client 135.161.105.164:50294] Malformed node revision ID string [400, #160062]
[Thu Mar 01 17:42:37.356665 2018] [dav:error] [pid 112152:tid 140359566870272] [client 135.161.105.164:50356] Malformed node revision ID string [400, #160062]
[Thu Mar 01 17:43:42.230627 2018] [dav:error] [pid 116212:tid 140359556380416] [client 135.161.105.164:50496] Provider encountered an error while streaming a REPORT response. [400, #0]
[Thu Mar 01 17:43:42.230635 2018] [dav:error] [pid 116212:tid 140359556380416] [client 135.161.105.164:50496] Malformed node revision ID string [400, #160062]
[Thu Mar 01 17:44:17.410198 2018] [dav:error] [pid 116212:tid 140359482951424] [client 135.161.105.164:50564] Provider encountered an error while streaming a REPORT response. [400, #0]
[Thu Mar 01 17:44:17.410222 2018] [dav:error] [pid 116212:tid 140359482951424] [client 135.161.105.164:50564] Malformed node revision ID string [400, #160062]
[Thu Mar 01 17:45:56.025740 2018] [dav:error] [pid 112151:tid 140359598339840] [client 135.161.105.164:50770] Provider encountered an error while streaming a REPORT response. [400, #0]
[Thu Mar 01 17:45:56.025755 2018] [dav:error] [pid 112151:tid 140359598339840] [client 135.161.105.164:50770] Malformed node revision ID string [400, #160062]
[Thu Mar 01 17:46:26.431448 2018] [dav:error] [pid 112166:tid 140359430502144] [client 135.161.105.164:50828] Malformed node revision ID string [400, #160062]
From: Paul Hammant [mailto:pa...@hammant.org]
Sent: Wednesday, February 28, 2018 8:28 AM
To: NOCERA, ANDY <an2...@att.com>
Cc: Andreas Krey <a.k...@gmx.de>; Michael Rohan <mro...@stonepillar.com>; us...@subversion.apache.org
Subject: Re: E130003: The XML response contains invalid XML - svn co and log issue on some repos using https/http
As you work toward a conclusion, Andy, do you think there was a different error message that could have driven you to root cause more quickly?
Johan Corveleyn
ID string" might point to a corruption in the repository. I've googled
a bit for this error message, and it seems to have been introduced in
this commit (was first release in 1.9.0):
http://svn.apache.org/viewvc?view=revision&revision=1622942
You said before that "svnadmin verify" did not report errors. Did you
use a 1.8 svnadmin, or a 1.9 svnadmin for that? It seems to me that
the verification was made more stringent in 1.9, thus detecting this
kind of corruption (where a malformed nod revision ID is in the
back-end data somewhere).
Maybe you should try to dump+load this repository into a new one, to
see if that fixes it.
--
Johan
NOCERA, ANDY
Good feedback.
Svnadmin 1.9 verify is showing the error also. I did a dump and load and it resolved that repo. Having reviewed my repos, it looks like around 30% have this issue. Not sure what we could have done wrong to cause it. A real simple repo is mine and has only a few commits shows the error. Is there a correction method quicker than a dump and load?
Thanks
Andy
-----Original Message-----
From: Johan Corveleyn [mailto:jco...@gmail.com]
Sent: Friday, March 02, 2018 5:12 AM
To: NOCERA, ANDY <an2...@att.com>
Cc: us...@subversion.apache.org
Subject: Re: E130003: The XML response contains invalid XML - svn co and log issue on some repos using https/http
Johan Corveleyn
> John,
>
> Good feedback.
>
> Svnadmin 1.9 verify is showing the error also. I did a dump and load and it resolved that repo. Having reviewed my repos, it looks like around 30% have this issue. Not sure what we could have done wrong to cause it. A real simple repo is mine and has only a few commits shows the error. Is there a correction method quicker than a dump and load?
>
It might be worth investigating why this happened to begin with. But I
don't really know where to start. One hypothesis is that this
corruption is already lingering there for years (until 1.9 it wouldn't
have been noticed) ... perhaps something outside of SVN manipulated
the rev files years ago? Or perhaps there was a bug once in SVN that
caused this to happen (but the corruption remained benign / unnoticed,
until the stricter validation by 1.9). It's also possible that the
stricter validation by 1.9 contains a bug, and is too strict for some
cases (though in that case I would have expected more reports on this
list).
Maybe you can make a more accurate hypothesis by investigating exactly
what the "Malformed node revision ID string"s looks like. Actually,
danielsh just improved that error message a few days ago, by adding
the actual data to the error message:
http://svn.apache.org/viewvc?view=revision&revision=1825846
So if you can build svn from source you might be able to perform a
build from the latest svn trunk, and run 'svnadmin verify' to get the
more verbose error message (be careful not to use your trunk svn build
on production data without creating a backup of course). Or
alternatively you can try taking a look into the rev files yourself,
to find the "malformed node revision ID".
--
Johan