[Cyberduck-trac] [Cyberduck] #7785: openstack swift server side copies read timeouts
Cyberduck
trac at trac.cyberduck.io
Tue Feb 11 11:05:47 UTC 2014
#7785: openstack swift server side copies read timeouts
---------------------------+---------------------------
Reporter: david cole | Owner:
Type: defect | Status: new
Priority: normal | Milestone:
Component: core | Version: 4.4.3
Severity: normal | Keywords: read timeout
Architecture: | Platform: Mac OS X 10.9
---------------------------+---------------------------
Hi,
One of our users reported many read timeout mesages when duplicating a
large container in Cyberduck 4.4.3
Using the duplicate function in Cyberduck on Openstack swift, the log
drawer shows that a server side copy is being performed - eg a PUT
operation with the X-Copy-From header set to another location within the
same cluster.
This works well for small files, but does time out on larger files with
the default timeout set. The customer saw a timeout with 1000MB files and
I can see it testing with a 4000MB files. I think around 800MB is the
threshold on our Openstack clusters. Here are the debug log messages
showing an example timeout on a single object which is quite big:
{{{
2014-02-11 10:41:17,652 [background-1] INFO ch.cyberduck.core.Session -
PUT /v1/AUTH_abcdefabcdefabc12312312312312312/dupe%20me%204 HTTP/1.1
2014-02-11 10:41:17,652 [background-1] INFO ch.cyberduck.core.Session - X
-Auth-Token: cbacbacbacbacbacabcbac
2014-02-11 10:41:17,652 [background-1] INFO ch.cyberduck.core.Session -
Content-Length: 0
2014-02-11 10:41:17,652 [background-1] INFO ch.cyberduck.core.Session -
Host: proxy-01.example.com
2014-02-11 10:41:17,652 [background-1] INFO ch.cyberduck.core.Session -
Connection: Keep-Alive
2014-02-11 10:41:17,652 [background-1] INFO ch.cyberduck.core.Session -
User-Agent: Cyberduck/4.4.3 (Mac OS X/10.9) (x86_64)
2014-02-11 10:41:17,653 [background-1] DEBUG
org.apache.http.impl.client.DefaultHttpClient - Attempt 1 to execute
request
2014-02-11 10:41:17,653 [background-1] DEBUG
org.apache.http.impl.conn.DefaultClientConnection - Sending request: PUT
/v1/AUTH_abcdefabcdefabc12312312312312312/dupe%20me%204 HTTP/1.1
2014-02-11 10:41:17,653 [background-1] DEBUG org.apache.http.headers - >>
PUT /v1/AUTH_abcdefabcdefabc12312312312312312/dupe%20me%204 HTTP/1.1
2014-02-11 10:41:17,653 [background-1] DEBUG org.apache.http.headers - >>
X-Auth-Token: cbacbacbacbacbacabcbac
2014-02-11 10:41:17,653 [background-1] DEBUG org.apache.http.headers - >>
Content-Length: 0
2014-02-11 10:41:17,653 [background-1] DEBUG org.apache.http.headers - >>
Host: proxy-01.example.com
2014-02-11 10:41:17,653 [background-1] DEBUG org.apache.http.headers - >>
Connection: Keep-Alive
2014-02-11 10:41:17,653 [background-1] DEBUG org.apache.http.headers - >>
User-Agent: Cyberduck/4.4.3 (Mac OS X/10.9) (x86_64)
2014-02-11 10:41:17,653 [background-1] DEBUG org.apache.http.headers - >>
Accept-Encoding: gzip,deflate
2014-02-11 10:41:18,510 [background-1] DEBUG
org.apache.http.impl.conn.DefaultClientConnection - Receiving response:
HTTP/1.1 201 Created
2014-02-11 10:41:18,510 [background-1] DEBUG org.apache.http.headers - <<
HTTP/1.1 201 Created
2014-02-11 10:41:18,510 [background-1] DEBUG org.apache.http.headers - <<
Content-Length: 0
2014-02-11 10:41:18,510 [background-1] DEBUG org.apache.http.headers - <<
Content-Type: text/html; charset=UTF-8
2014-02-11 10:41:18,510 [background-1] DEBUG org.apache.http.headers - <<
Date: Tue, 11 Feb 2014 10:41:14 GMT
2014-02-11 10:41:18,510 [background-1] DEBUG org.apache.http.headers - <<
Connection: keep-alive
2014-02-11 10:41:18,510 [background-1] INFO ch.cyberduck.core.Session -
HTTP/1.1 201 Created
2014-02-11 10:41:18,510 [background-1] INFO ch.cyberduck.core.Session -
Content-Length: 0
2014-02-11 10:41:18,510 [background-1] INFO ch.cyberduck.core.Session -
Content-Type: text/html; charset=UTF-8
2014-02-11 10:41:18,510 [background-1] INFO ch.cyberduck.core.Session -
Date: Tue, 11 Feb 2014 10:41:14 GMT
2014-02-11 10:41:18,510 [background-1] INFO ch.cyberduck.core.Session -
Connection: keep-alive
2014-02-11 10:41:18,510 [background-1] DEBUG
org.apache.http.impl.client.DefaultHttpClient - Connection can be kept
alive indefinitely
2014-02-11 10:41:18,510 [background-1] DEBUG
org.apache.http.impl.conn.PoolingClientConnectionManager - Connection [id:
24][route: {s}->https://proxy-01.example.com] can be kept alive
indefinitely
2014-02-11 10:41:18,510 [background-1] DEBUG
org.apache.http.impl.conn.PoolingClientConnectionManager - Connection
released: [id: 24][route: {s}->https://proxy-01.example.com][total kept
alive: 3; route allocated: 2 of 2147483647; total allocated: 3 of
2147483647]
2014-02-11 10:41:18,511 [background-1] DEBUG
ch.cyberduck.core.transfer.CopyTransfer - Transfer file /dupe
me/CentOS-5.8-x86_64-bin-DVD-1of2.iso with options
TransferOptions{resumeRequested=false, reloadRequested=false,
quarantine=true}
2014-02-11 10:41:18,511 [background-1] INFO ch.cyberduck.core.Session -
Copying CentOS-5.8-x86_64-bin-DVD-1of2.iso to CentOS-5.8-x86_64-bin-DVD-
1of2.iso
2014-02-11 10:41:18,512 [background-1] WARN
ch.cyberduck.core.openstack.SwiftRegionService - Unknown region null in
authentication context
2014-02-11 10:41:18,512 [background-1] WARN
ch.cyberduck.core.openstack.SwiftRegionService - Fallback to first region
found null
2014-02-11 10:41:18,512 [background-1] WARN
ch.cyberduck.core.openstack.SwiftRegionService - No CDN management
endpoint found for region null
2014-02-11 10:41:18,513 [background-1] DEBUG
org.apache.http.impl.conn.PoolingClientConnectionManager - Connection
request: [route: {s}->https://proxy-01.example.com][total kept alive: 22;
route allocated: 21 of 2147483647; total allocated: 22 of 2147483647]
2014-02-11 10:41:18,513 [background-1] DEBUG
org.apache.http.impl.conn.PoolingClientConnectionManager - Connection
leased: [id: 1][route: {s}->https://proxy-01.example.com][total kept
alive: 21; route allocated: 21 of 2147483647; total allocated: 22 of
2147483647]
2014-02-11 10:41:18,513 [background-1] DEBUG
org.apache.http.impl.client.DefaultHttpClient - Stale connection check
2014-02-11 10:41:18,514 [background-1] DEBUG
org.apache.http.client.protocol.RequestAddCookies - CookieSpec selected:
best-match
2014-02-11 10:41:18,514 [background-1] DEBUG
org.apache.http.client.protocol.RequestAuthCache - Auth cache not set in
the context
2014-02-11 10:41:18,514 [background-1] DEBUG
org.apache.http.client.protocol.RequestTargetAuthentication - Target auth
state: UNCHALLENGED
2014-02-11 10:41:18,514 [background-1] DEBUG
org.apache.http.client.protocol.RequestProxyAuthentication - Proxy auth
state: UNCHALLENGED
2014-02-11 10:41:18,515 [background-1] INFO ch.cyberduck.core.Session -
PUT
/v1/AUTH_abcdefabcdefabc12312312312312312/dupe%20me%204/CentOS-5.8-x86_64
-bin-DVD-1of2.iso HTTP/1.1
2014-02-11 10:41:18,515 [background-1] INFO ch.cyberduck.core.Session - X
-Copy-From: dupe%20me/CentOS-5.8-x86_64-bin-DVD-1of2.iso
2014-02-11 10:41:18,515 [background-1] INFO ch.cyberduck.core.Session - X
-Auth-Token: cbacbacbacbacbacabcbac
2014-02-11 10:41:18,515 [background-1] INFO ch.cyberduck.core.Session -
Content-Length: 0
2014-02-11 10:41:18,515 [background-1] INFO ch.cyberduck.core.Session -
Host: proxy-01.example.com
2014-02-11 10:41:18,515 [background-1] INFO ch.cyberduck.core.Session -
Connection: Keep-Alive
2014-02-11 10:41:18,516 [background-1] INFO ch.cyberduck.core.Session -
User-Agent: Cyberduck/4.4.3 (Mac OS X/10.9) (x86_64)
2014-02-11 10:41:18,516 [background-1] DEBUG
org.apache.http.impl.client.DefaultHttpClient - Attempt 1 to execute
request
2014-02-11 10:41:18,516 [background-1] DEBUG
org.apache.http.impl.conn.DefaultClientConnection - Sending request: PUT
/v1/AUTH_abcdefabcdefabc12312312312312312/dupe%20me%204/CentOS-5.8-x86_64
-bin-DVD-1of2.iso HTTP/1.1
2014-02-11 10:41:18,516 [background-1] DEBUG org.apache.http.headers - >>
PUT
/v1/AUTH_abcdefabcdefabc12312312312312312/dupe%20me%204/CentOS-5.8-x86_64
-bin-DVD-1of2.iso HTTP/1.1
2014-02-11 10:41:18,516 [background-1] DEBUG org.apache.http.headers - >>
X-Copy-From: dupe%20me/CentOS-5.8-x86_64-bin-DVD-1of2.iso
2014-02-11 10:41:18,516 [background-1] DEBUG org.apache.http.headers - >>
X-Auth-Token: cbacbacbacbacbacabcbac
2014-02-11 10:41:18,516 [background-1] DEBUG org.apache.http.headers - >>
Content-Length: 0
2014-02-11 10:41:18,516 [background-1] DEBUG org.apache.http.headers - >>
Host: proxy-01.example.com
2014-02-11 10:41:18,516 [background-1] DEBUG org.apache.http.headers - >>
Connection: Keep-Alive
2014-02-11 10:41:18,516 [background-1] DEBUG org.apache.http.headers - >>
User-Agent: Cyberduck/4.4.3 (Mac OS X/10.9) (x86_64)
2014-02-11 10:41:18,516 [background-1] DEBUG org.apache.http.headers - >>
Accept-Encoding: gzip,deflate
<< paused here >>
2014-02-11 10:41:48,521 [background-1] DEBUG
org.apache.http.impl.conn.DefaultClientConnection - Connection
0.0.0.0:61315<->193.203.66.230:443 closed
2014-02-11 10:41:48,522 [background-1] DEBUG
org.apache.http.impl.client.DefaultHttpClient - Closing the connection.
2014-02-11 10:41:48,522 [background-1] DEBUG
org.apache.http.impl.conn.DefaultClientConnection - Connection
0.0.0.0:61315<->193.203.66.230:443 closed
2014-02-11 10:41:48,522 [background-1] DEBUG
org.apache.http.impl.conn.DefaultClientConnection - Connection
0.0.0.0:61315<->193.203.66.230:443 shut down
2014-02-11 10:41:48,523 [background-1] DEBUG
org.apache.http.impl.conn.DefaultClientConnection - Connection
0.0.0.0:61315<->193.203.66.230:443 closed
2014-02-11 10:41:48,523 [background-1] DEBUG
org.apache.http.impl.conn.PoolingClientConnectionManager - Connection
released: [id: 1][route: {s}->https://proxy-01.example.com][total kept
alive: 21; route allocated: 20 of 2147483647; total allocated: 21 of
2147483647]
2014-02-11 10:41:48,534 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidChangeBackingProperties:
2014-02-11 10:41:48,534 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowWillMove:
2014-02-11 10:41:48,534 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowWillExitVersionBrowser:
2014-02-11 10:41:48,535 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidUpdate:
2014-02-11 10:41:48,535 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidResize:
2014-02-11 10:41:48,535 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidMiniaturize:
2014-02-11 10:41:48,535 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidEnterFullScreen:
2014-02-11 10:41:48,535 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidExitFullScreen:
2014-02-11 10:41:48,535 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidChangeOcclusionState:
2014-02-11 10:41:48,535 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidMove:
2014-02-11 10:41:48,535 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidEndSheet:
2014-02-11 10:41:48,535 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowWillOrderOffScreen:
2014-02-11 10:41:48,535 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidOrderOnScreen:
2014-02-11 10:41:48,535 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidExpose:
2014-02-11 10:41:48,535 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidEndLiveResize:
2014-02-11 10:41:48,535 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowWillMiniaturize:
2014-02-11 10:41:48,535 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidExitVersionBrowser:
2014-02-11 10:41:48,535 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidOrderOffScreen:
2014-02-11 10:41:48,536 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowWillEnterVersionBrowser:
2014-02-11 10:41:48,536 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidChangeScreenProfile:
2014-02-11 10:41:48,536 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidEnterVersionBrowser:
2014-02-11 10:41:48,536 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidDeminiaturize:
2014-02-11 10:41:48,536 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowWillOrderOnScreen:
2014-02-11 10:41:48,536 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowDidChangeScreen:
2014-02-11 10:41:48,536 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowWillStartLiveResize:
2014-02-11 10:41:48,536 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowWillBeginSheet:
2014-02-11 10:41:48,536 [background-1] DEBUG org.rococoa.callback - No
method for selector:validRequestorForSendType:returnType:
2014-02-11 10:41:48,536 [background-1] DEBUG org.rococoa.callback - No
method for selector:windowWillReturnFieldEditor:toObject:
2014-02-11 10:41:48,536 [background-1] DEBUG org.rococoa.callback - No
method for selector:window:willEncodeRestorableState:
2014-02-11 10:41:48,554 [main] DEBUG org.rococoa.callback - No method for
selector:window:willPositionSheet:usingRect:
2014-02-11 10:41:48,887 [background-1] DEBUG
ch.cyberduck.ui.cocoa.SheetController - Await sheet dismiss
2014-02-11 10:42:14,267 [Finalizer] DEBUG org.rococoa - Draining
autorelease pool
2014-02-11 10:42:14,282 [Finalizer] DEBUG org.rococoa - Draining
autorelease pool
2014-02-11 10:42:14,291 [Finalizer] DEBUG org.rococoa - Draining
autorelease pool
2014-02-11 10:42:14,301 [Finalizer] DEBUG org.rococoa - Draining
autorelease pool
2014-02-11 10:42:14,303 [main] DEBUG org.rococoa.callback - No method for
selector:undoManagerForWindow:
2014-02-11 10:42:14,303 [main] DEBUG org.rococoa.callback - No method for
selector:windowWillReturnUndoManager:
2014-02-11 10:42:14,307 [Finalizer] DEBUG org.rococoa - Draining
autorelease pool
2014-02-11 10:42:14,316 [Finalizer] DEBUG org.rococoa - Draining
autorelease pool
2014-02-11 10:42:16,396 [main] DEBUG ch.cyberduck.ui.cocoa.SheetController
- Close sheet with button Continue
2014-02-11 10:42:16,734 [background-1] WARN
ch.cyberduck.ui.action.AbstractTransferWorker - Ignore transfer failure
Cannot copy CentOS-5.8-x86_64-bin-DVD-1of2.iso (/dupe me/CentOS-5.8-x86_64
-bin-DVD-1of2.iso). Read timed out.
}}}
This has similarities to Ticket #7732 " Bulk delete can appear to
timeout." - is that ticket, the older version of swift did not send any
data during the long running bulk-delete, but the sending of white space
in more recent versions of swift means that the client will not timeout -
this is not the case for the Server Side copy. I have looked at the swift
CHANGELOG and I don't see an improvement to the X-Copy-From logic to send
whitespace or workaround this issue there.
Is there anything we can do in Cyberduck. One theory - If we know how
large the file is we could estimate how long the server side copy is
likely to take and set the timeout for that operation (if preference
timeout is < estimate)
--
Ticket URL: <https://trac.cyberduck.io/ticket/7785>
Cyberduck <http://cyberduck.io>
Libre FTP, SFTP, WebDAV, S3 & OpenStack Swift browser for Mac and Windows
More information about the Cyberduck-trac
mailing list