Subject: Re: [[email protected]] Strange WebDAV behavior on MKCOL
for 1 client only



It looks like a problem with the implementation or configuration in the client.The actual source of your 400 error is this:[auth_digest:error] [pid 3880:tid 1132] [client yyy.yyy.yyy.yy:61411] AH01786: uri mismatch - </webdav/dir1/dir2/dir3/dir4/dir5/dir6> does not match request-uri </webdav/dir1/dir2/dir3/dir4/dir5/dir6/>

This is because your Authorization header has - as the error message clearly states - a mismatch.
On your working connection:Authorization: [...] uri="/webdav/dir1/dir2/dir3/dir4/dir5/dir6/", [...] 

On your broken connection:Authorization: [...] uri="/webdav/dir1/dir2/dir3/dir4/dir5/dir6", [...]
Note the missing trailing slash in your authorization header.I suspect if you figure out why you are getting that, everything will start working.
- Y
On Mon, Aug 7, 2017 at 6:22 PM, Todd Blum <[email protected]> wrote:
OK, here is the MKCOL of a working client:
_____________________________________________________________________________________________________________________________

[Mon Aug 07 14:47:04.258261 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(135): [client xxx.xxx.xxx.xx:45537] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(58): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_in (data-TRANSIENT): 48 bytes[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(100): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_in (data-TRANSIENT): MKCOL /webdav/dir1/dir2/dir3/dir4/dir5/dir6/ HTTP/1.1\r\n[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(135): [client xxx.xxx.xxx.xx:45537] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(58): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_in (data-TRANSIENT): 40 bytes[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(100): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_in (data-TRANSIENT): User-Agent: cadaver/0.23.3 neon/0.30.1\r\n[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(135): [client xxx.xxx.xxx.xx:45537] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(58): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_in (data-TRANSIENT): 16 bytes[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(100): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_in (data-TRANSIENT): Connection: TE\r\n[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(135): [client xxx.xxx.xxx.xx:45537] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(58): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_in (data-TRANSIENT): 14 bytes[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(100): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_in (data-TRANSIENT): TE: trailers\r\n[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(135): [client xxx.xxx.xxx.xx:45537] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(58): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_in (data-TRANSIENT): 35 bytes[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(100): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_in (data-TRANSIENT): Host: server.hostname.com\r\n[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(135): [client xxx.xxx.xxx.xx:45537] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(58): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_in (data-TRANSIENT): 294 bytes[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(100): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_in (data-TRANSIENT): Authorization: Digest username="username", realm="DAV-upload", nonce="+IgWxjBWBQA=2843abd2bf8b6c81d9bb74b327a39443ed91d830", uri="/webdav/dir1/dir2/dir3/dir4/dir5/dir6/", response="9c0d5a0f57c74963d357f235c50305a5", algorithm="MD5", cnonce="97fe93201c8279fa490d1338d455d466", nc=00000003, qop="auth"\r\n[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(135): [client xxx.xxx.xxx.xx:45537] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(58): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_in (data-TRANSIENT): 2 bytes[Mon Aug 07 14:47:04.329225 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(100): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_in (data-TRANSIENT): \r\n
[Mon Aug 07 14:47:04.331226 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(164): [client xxx.xxx.xxx.xx:45537] mod_dumpio: dumpio_out[Mon Aug 07 14:47:04.331226 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(58): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_out (data-HEAP): 197 bytes[Mon Aug 07 14:47:04.331226 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(100): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_out (data-HEAP): HTTP/1.1 405 Method Not Allowed\r\nDate: Mon, 07 Aug 2017 21:47:04 GMT\r\nServer: Apache/2.4.4 (Win64) OpenSSL/1.0.1e\r\nAllow: TRACE\r\nContent-Length: 253\r\nContent-Type: text/html; charset=iso-8859-1\r\n\r\n[Mon Aug 07 14:47:04.331226 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(164): [client xxx.xxx.xxx.xx:45537] mod_dumpio: dumpio_out[Mon Aug 07 14:47:04.331226 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(58): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_out (data-HEAP): 253 bytes[Mon Aug 07 14:47:04.331226 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(100): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_out (data-HEAP): <!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">\n<html><head>\n<title>405 Method Not Allowed</title>\n</head><body>\n<h1>Method Not Allowed</h1>\n<p>The requested method MKCOL is not allowed for the URL /webdav/dir1/dir2/dir3/dir4/dir5/dir6/.</p>\n</body></html>\n[Mon Aug 07 14:47:04.331226 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(58): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_out (metadata-EOS): 0 bytes[Mon Aug 07 14:47:04.331226 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(164): [client xxx.xxx.xxx.xx:45537] mod_dumpio: dumpio_out[Mon Aug 07 14:47:04.331226 2017] [dumpio:trace7] [pid 3104:tid 1132] mod_dumpio.c(58): [client xxx.xxx.xxx.xx:45537] mod_dumpio:  dumpio_out (metadata-EOR): 0 bytes
_____________________________________________________________________________________________________________________________


and here is the non-working MKCOL:
_____________________________________________________________________________________________________________________________

[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(135): [client yyy.yyy.yyy.yy:61411] mod_dumpio: dumpio_in [speculative-nonblocking] 1 readbytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(58): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): 1 bytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(100): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): M[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(135): [client yyy.yyy.yyy.yy:61411] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(58): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): 48 bytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(100): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): MKCOL /webdav/dir1/dir2/dir3/dir4/dir5/dir6/ HTTP/1.1\r\n[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(135): [client yyy.yyy.yyy.yy:61411] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(58): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): 13 bytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(100): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): Accept: */*\r\n[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(135): [client yyy.yyy.yyy.yy:61411] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(58): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): 32 bytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(100): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): Accept-Encoding: gzip, deflate\r\n[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(135): [client yyy.yyy.yyy.yy:61411] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(58): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): 65 bytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(100): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): User-Agent: Mozilla/4.0 (compatible; Clever Internet Suite 6.2)\r\n[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(135): [client yyy.yyy.yyy.yy:61411] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(58): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): 24 bytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(100): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): Connection: Keep-Alive\r\n[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(135): [client yyy.yyy.yyy.yy:61411] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(58): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): 293 bytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(100): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): Authorization: Digest username="username", realm="DAV-upload", qop="auth", algorithm="MD5", uri="/webdav/dir1/dir2/dir3/dir4/dir5/dir6", nonce="1sn6zjBWBQA=124cb4760097cff44f4c97d8c9945a5a920a8c05", nc=00000001, cnonce="ab08070e302202030f6049540f604955", response="64efa6e2ced2ae1ab4d9e5f64a60fcf8"\r\n[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(135): [client yyy.yyy.yyy.yy:61411] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(58): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): 35 bytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(100): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): Host: server.hostname.com\r\n[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(135): [client yyy.yyy.yyy.yy:61411] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(58): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): 2 bytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(100): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_in (data-TRANSIENT): \r\n[Mon Aug 07 14:48:34.517391 2017] [auth_digest:error] [pid 3880:tid 1132] [client yyy.yyy.yyy.yy:61411] AH01786: uri mismatch - </webdav/dir1/dir2/dir3/dir4/dir5/dir6> does not match request-uri </webdav/dir1/dir2/dir3/dir4/dir5/dir6/>
[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(164): [client yyy.yyy.yyy.yy:61411] mod_dumpio: dumpio_out[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(58): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_out (data-HEAP): 195 bytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(100): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_out (data-HEAP): HTTP/1.1 400 Bad Request\r\nDate: Mon, 07 Aug 2017 21:48:34 GMT\r\nServer: Apache/2.4.4 (Win64) OpenSSL/1.0.1e\r\nContent-Length: 226\r\nConnection: close\r\nContent-Type: text/html; charset=iso-8859-1\r\n\r\n[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(164): [client yyy.yyy.yyy.yy:61411] mod_dumpio: dumpio_out[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(58): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_out (data-HEAP): 226 bytes[Mon Aug 07 14:48:34.517391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(100): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_out (data-HEAP): <!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">\n<html><head>\n<title>400 Bad Request</title>\n</head><body>\n<h1>Bad Request</h1>\n<p>Your browser sent a request that this server could not understand.<br />\n</p>\n</body></html>\n[Mon Aug 07 14:48:34.518391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(58): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_out (metadata-EOS): 0 bytes[Mon Aug 07 14:48:34.518391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(164): [client yyy.yyy.yyy.yy:61411] mod_dumpio: dumpio_out[Mon Aug 07 14:48:34.518391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(58): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_out (metadata-EOR): 0 bytes[Mon Aug 07 14:48:34.518391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(164): [client yyy.yyy.yyy.yy:61411] mod_dumpio: dumpio_out[Mon Aug 07 14:48:34.518391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(58): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_out (metadata-FLUSH): 0 bytes[Mon Aug 07 14:48:34.518391 2017] [dumpio:trace7] [pid 3880:tid 1132] mod_dumpio.c(58): [client yyy.yyy.yyy.yy:61411] mod_dumpio:  dumpio_out (metadata-EOC): 0 bytes_____________________________________________________________________________________________________________________________

Todd
On Mon, Aug 7, 2017 at 5:07 PM, Yehuda Katz <[email protected]> wrote:
Try mod_dumpio or a packet capture to see what else is different about the request.
- Y
On Mon, Aug 7, 2017 at 3:53 PM, Todd Blum <[email protected]> wrote:
Hello,
I have Apache mod_dav running on Windows 2012.  
When a webDAV enabled application connects and tries to MKCOL on a directory that already exists, it receives an HTTP 400:
____________________________________________________________________________

yyy.yyy.yyy.yy - username [07/Aug/2017:11:00:03 -0700] "MKCOL /webdav/dir1/dir2/dir3/dir4/dir5/dir6/ HTTP/1.1" 400 226____________________________________________________________________________


However, all other clients are receiving an HTTP 405 when they issue a MKCOL for a directory that already exists:
____________________________________________________________________________

xxx.xxx.xxx.xx - username [07/Aug/2017:12:32:16 -0700] "MKCOL /webdav/dir1/dir2/dir3/dir4/dir5/dir6/ HTTP/1.1" 405 253____________________________________________________________________________


The application is dependent on receiving a 405 in this scenario, has anyone else had this situation before?

Todd





Programming list archiving by: Enterprise Git Hosting