Creating a new file on WebDAV server never finishes

[https://me.yahoo.com/a/egOlVSM0t4gxRszZM8CTQenaz5oJ#9fa8f]

I have set up an Apache 2.2 server as WebDAV storage provider via https. I have no trouble connecting to the server an listing the directory. Apache2 has read&write permissions to the WebDAV base. Creating directories through Cyberduck works as expected, most times uploading files is no problem.

However always when I want to create a new file on the server through the menu entry in Cyberduck, that action never finishes. 'Prepare [filename]' is displayed indefinitely. A file with size 0 of that name is created in the directory however. Sometimes the same behavior is seen with other files, but I cannot reproduce that reliably. Stopping that upload then ends in an indefinite display of 'Disconnecting [servername]'

In the logfiles I see different entries for the successful put and the unsuccessful (putting default.jpg was successful, testfile was unsuccessful&stuck in 'Prepare testfile' a file with the name testfile has been created however):

192.20.4.40 - - [01/Nov/2011:23:17:49 +0100] "PROPFIND / HTTP/1.1" 401 4535 "-" "Cyberduck/4.1 (Mac OS X/10.6.8) (i386)"

192.20.4.40 - testuser [01/Nov/2011:23:17:49 +0100] "PROPFIND / HTTP/1.1" 207 1315 "-" "Cyberduck/4.1 (Mac OS X/10.6.8) (i386)"

192.20.4.40 - - [01/Nov/2011:23:17:59 +0100] "PROPFIND / HTTP/1.1" 401 4535 "-" "Cyberduck/4.1 (Mac OS X/10.6.8) (i386)"

192.20.4.40 - testuser [01/Nov/2011:23:17:59 +0100] "PROPFIND / HTTP/1.1" 207 1315 "-" "Cyberduck/4.1 (Mac OS X/10.6.8) (i386)"

192.20.4.40 - testuser [01/Nov/2011:23:17:59 +0100] "PUT /default.jpg HTTP/1.1" 201 753 "-" "Cyberduck/4.1 (Mac OS X/10.6.8) (i386)"

192.20.4.40 - testuser [01/Nov/2011:23:18:09 +0100] "PROPFIND / HTTP/1.1" 207 1347 "-" "Cyberduck/4.1 (Mac OS X/10.6.8) (i386)"

192.20.4.40 - testuser [01/Nov/2011:23:18:09 +0100] "MKCOL /testfolder/ HTTP/1.1" 201 702 "-" "Cyberduck/4.1 (Mac OS X/10.6.8) (i386)"

192.20.4.40 - testuser [01/Nov/2011:23:18:18 +0100] "PUT /testfile HTTP/1.1" 201 663 "-" "Cyberduck/4.1 (Mac OS X/10.6.8) (i386)"

[https://me.yahoo.com/a/egOlVSM0t4gxRszZM8CTQenaz5oJ#9fa8f]

To rule out a configuration error on the server side (it is my first WebDAV setup) or aid reproduction of the issue the apache vhost file for the server:

<IfModule mod_dav_fs.c>
DAVLockDB /srv/www/webdav/lock/davlockdb
</IfModule>
<IfModule mod_ssl.c>
<VirtualHost *:443>
        ServerAdmin webmaster@testhost
        ServerName  files.testhost.lan
        ServerAlias files.localnet.lan
        
        DocumentRoot /srv/www/webdav/files

        <Location />
           DAV On
           AuthType Basic
           AuthName "WebDAV Access"
           AuthUserFile /srv/www/webdav/webdav-users
           Require valid-user
       </Location>

        CustomLog ${APACHE_LOG_DIR}/webdav-ssl_access.log combined
        ErrorLog ${APACHE_LOG_DIR}/webdav-ssl_error.log
        LogLevel warn

        SSLEngine on
        SSLCertificateFile    /etc/ssl/local/certs/testhost.crt
        SSLCertificateKeyFile /etc/ssl/local/private/testhost.key
        SSLCertificateChainFile /etc/ssl/local/certs/localCA-1.server.ca.pem
        SSLCACertificateFile /etc/ssl/local/certs/localCA.pem
</VirtualHost>
</IfModule>

If additional information would be helpful I will be happy to supply it.

[dkocher]

Can you find any related output in the system.log (/Applications/Utilities/Console.app)?

[https://me.yahoo.com/a/egOlVSM0t4gxRszZM8CTQenaz5oJ#9fa8f]

No related log entries at all. Can I somehow enable a debug mode/verbose logging in Cyberduck?

[https://me.yahoo.com/a/egOlVSM0t4gxRszZM8CTQenaz5oJ#9fa8f]

unfortunately I cannot post it (it is rejected as spam by trac and the captcha does not work) (managed to post it eventually by editing

All right, I have enabled the debug mode. The action I performed was 'New file' with filename 'loremipsum.txt'

To my untrained eye one part of the log jumps out:

Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,589 [background-4] DEBUG ch.cyberduck.core.UploadTransfer - init
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,589 [background-4] DEBUG ch.cyberduck.core.io.BandwidthThrottle - setRate:-1.0
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,590 [background-4] DEBUG ch.cyberduck.core.Transfer - start:ch.cyberduck.core.Path$2@6bb93c
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,590 [background-4] DEBUG ch.cyberduck.core.Transfer - fireTransferWillStart:ch.cyberduck.core.UploadTransfer@4e50ee
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,590 [background-4] DEBUG ch.cyberduck.core.Transfer - queue:ch.cyberduck.core.UploadTransfer@4e50ee
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,591 [background-4] DEBUG ch.cyberduck.core.Transfer - add:ch.cyberduck.core.UploadTransfer@4e50ee
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,592 [background-4] DEBUG ch.cyberduck.core.Transfer - Checking connnection
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,592 [background-4] DEBUG ch.cyberduck.core.Transfer - check:ch.cyberduck.core.UploadTransfer@4e50ee
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,592 [background-4] DEBUG ch.cyberduck.core.UploadTransfer - action:false,false
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,592 [background-4] DEBUG ch.cyberduck.core.Transfer - clear:ch.cyberduck.core.TransferOptions@191f022
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,592 [background-4] DEBUG ch.cyberduck.core.UploadTransfer - normalize
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,592 [background-4] DEBUG ch.cyberduck.core.Transfer - check:ch.cyberduck.core.UploadTransfer@4e50ee
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,592 [background-4] INFO  ch.cyberduck.core.Session - Prepare loremipsum.txt
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,596 [background-4] DEBUG ch.cyberduck.core.Transfer - check:ch.cyberduck.core.UploadTransfer@4e50ee
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,596 [background-4] DEBUG ch.cyberduck.core.UploadTransfer - filter:ask
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,596 [background-4] DEBUG ch.cyberduck.core.Transfer - check:ch.cyberduck.core.UploadTransfer@4e50ee
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,596 [background-4] DEBUG ch.cyberduck.core.UploadTransfer - filter:overwrite
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,596 [background-4] DEBUG ch.cyberduck.core.Transfer - reset:ch.cyberduck.core.UploadTransfer@4e50ee
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,596 [background-4] DEBUG ch.cyberduck.core.Transfer - prepare:/loremipsum.txt
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,596 [background-4] DEBUG ch.cyberduck.core.Transfer - check:ch.cyberduck.core.UploadTransfer@4e50ee
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,596 [background-4] INFO  ch.cyberduck.core.Transfer - Accepted in transfer:/loremipsum.txt
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,596 [background-4] INFO  ch.cyberduck.core.Session - Prepare loremipsum.txt
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,598 [background-4] DEBUG ch.cyberduck.core.Transfer - check:ch.cyberduck.core.UploadTransfer@4e50ee
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,598 [background-4] DEBUG ch.cyberduck.core.UploadTransfer - transfer:/loremipsum.txt
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,603 [http-1] DEBUG org.jets3t.service.utils.Mimetypes - Loading mime types from file in the classpath: mime.types
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: 2011-11-04 12:48:46,603 [http-1] DEBUG org.jets3t.service.utils.Mimetypes - Setting mime type for extension 'ez' to 'application/andrew-inset'
...[a lot of similar messages]...
Nov  4 12:48:46 testclient [0x0-0x182182].ch.sudo.cyberduck[1196]: *** process 1196 exceeded 500 log message per second limit  -  remaining messages this second discarded ***

[dkocher]

Can you search for messages that have the status ERROR.

[https://me.yahoo.com/a/egOlVSM0t4gxRszZM8CTQenaz5oJ#9fa8f]

No entries with an ERROR status.

[https://me.yahoo.com/a/egOlVSM0t4gxRszZM8CTQenaz5oJ#9fa8f]

I just wanted to add I have tried out the Windows version of Cyberduck and another WebDAV-connector on the same server: no problem at all, so I suppose that rules out a server issue.

[dkocher]

Replying to https://me.yahoo.com/a/egOlVSM0t4gxRszZM8CTQenaz5oJ#9fa8f:

To rule out a configuration error on the server side (it is my first WebDAV setup) or aid reproduction of the issue the apache vhost file for the server:

Configuration looks fine.

[dkocher]

Please update to the latest ​snapshot build available just in case.

[https://me.yahoo.com/a/egOlVSM0t4gxRszZM8CTQenaz5oJ#9fa8f]

The latest snaphot is working correctly.

[dkocher]

This was fixed in r9044.