{"action":"created","issue":{"url":"https://api.github.com/repos/s3tools/s3cmd/issues/737","repository_url":"https://api.github.com/repos/s3tools/s3cmd","labels_url":"https://api.github.com/repos/s3tools/s3cmd/issues/737/labels{/name}","comments_url":"https://api.github.com/repos/s3tools/s3cmd/issues/737/comments","events_url":"https://api.github.com/repos/s3tools/s3cmd/issues/737/events","html_url":"https://github.com/s3tools/s3cmd/issues/737","id":153666319,"number":737,"title":"400 RequestTimeout - s3cmd is not re-trying","user":{"login":"jblachly","id":5987153,"avatar_url":"https://avatars.githubusercontent.com/u/5987153?v=3","gravatar_id":"","url":"https://api.github.com/users/jblachly","html_url":"https://github.com/jblachly","followers_url":"https://api.github.com/users/jblachly/followers","following_url":"https://api.github.com/users/jblachly/following{/other_user}","gists_url":"https://api.github.com/users/jblachly/gists{/gist_id}","starred_url":"https://api.github.com/users/jblachly/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/jblachly/subscriptions","organizations_url":"https://api.github.com/users/jblachly/orgs","repos_url":"https://api.github.com/users/jblachly/repos","events_url":"https://api.github.com/users/jblachly/events{/privacy}","received_events_url":"https://api.github.com/users/jblachly/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":4,"created_at":"2016-05-08T17:02:33Z","updated_at":"2016-09-04T22:17:13Z","closed_at":null,"body":"`s3cmd version 1.6.1`\r\n`SunOS cloudbackup 5.11 joyent_20160428T170316Z i86pc i386 i86pc Solaris`\r\n\r\nWhen doing an initial sync of about 100k files to S3:\r\n\r\n`s3cmd sync /path/to/photos s3://photo-archive-bucket/`\r\n\r\n.. plenty of successes for > 12 hours (averaging 600 kB/sec) ...\r\nthen:\r\n\r\n    WARNING: photos/Photos/20 - Mexico - Group1.jpg: Owner groupname not known. Storing GID=100 instead.\r\n    upload: 'photos/Photos/20 - Mexico - Group1.jpg' -> 's3://photo-archive-bucket/photos/Photos/20 - Mexico - Group1.jpg'  [15078 of 53083]\r\n    313221 of 313221   100% in   33s     9.00 kB/s  done\r\n    ERROR: S3 error: 400 (RequestTimeout): Your socket connection to the server was not read from or written to within the timeout period. Idle connections will be closed.\r\n\r\nI found the following (very old) issue in AWS' official repository:\r\n[https://github.com/aws/aws-sdk-js/issues/281](https://github.com/aws/aws-sdk-js/issues/281)\r\nIt seems like in most cases the S3 error `400 RequestTimeout Your socket connection to the server was not read from or written to within the timeout period. Idle connections will be closed.` is related to incorrect content-length header. However, I had not run with --debug and so cannot confirm.\r\n\r\nImportantly, and the reason I am filing this issue, is that I also found the following on the s3tools mailing list:\r\n[https://sourceforge.net/p/s3tools/mailman/message/25713745/](https://sourceforge.net/p/s3tools/mailman/message/25713745/)\r\nThis indicates that the code had been fixed to retry on 400 status codes.\r\n\r\nIndeed, looking at the s3cmd source code:\r\n[https://github.com/s3tools/s3cmd/blob/master/S3/S3.py#L1289](https://github.com/s3tools/s3cmd/blob/master/S3/S3.py#L1289)\r\nIt should be retrying (up to 5 times total as the S3 class _max_retries is initialized at 5), but it is not.  Why not?\r\n\r\nThe 9.00 kB/s (my other files all transmitted at > 600 kB/sec) suggest perhaps I had an intermittent internet connectivity issue. EVEN SO, s3cmd should have retried several additional times. \r\n\r\nLooking at the code path this could happen if\r\n\r\n1. retries is initialized as 0 -- I don't see this happening, but I could have missed it\r\n2. `if err.code in [ 'BadDigest', 'OperationAborted', 'TokenRefreshRequired', 'RequestTimeout' ]:` evaluates to false, which would then skip the `if try_retry:` block and fall through to `raise S3Error(response)`. \r\n\r\nCondition 2 could happen if the `response` did not have a key `data` or `data` were empty:\r\n[https://github.com/s3tools/s3cmd/blob/master/S3/Exceptions.py#L52](https://github.com/s3tools/s3cmd/blob/master/S3/Exceptions.py#L52)\r\n\r\nAny other suggestions for debugging?\r\n"},"comment":{"url":"https://api.github.com/repos/s3tools/s3cmd/issues/comments/244631896","html_url":"https://github.com/s3tools/s3cmd/issues/737#issuecomment-244631896","issue_url":"https://api.github.com/repos/s3tools/s3cmd/issues/737","id":244631896,"user":{"login":"jblachly","id":5987153,"avatar_url":"https://avatars.githubusercontent.com/u/5987153?v=3","gravatar_id":"","url":"https://api.github.com/users/jblachly","html_url":"https://github.com/jblachly","followers_url":"https://api.github.com/users/jblachly/followers","following_url":"https://api.github.com/users/jblachly/following{/other_user}","gists_url":"https://api.github.com/users/jblachly/gists{/gist_id}","starred_url":"https://api.github.com/users/jblachly/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/jblachly/subscriptions","organizations_url":"https://api.github.com/users/jblachly/orgs","repos_url":"https://api.github.com/users/jblachly/repos","events_url":"https://api.github.com/users/jblachly/events{/privacy}","received_events_url":"https://api.github.com/users/jblachly/received_events","type":"User","site_admin":false},"created_at":"2016-09-04T22:17:13Z","updated_at":"2016-09-04T22:17:13Z","body":"@fviard This only seems to happen during long uploads ; I wasn't (back in May) able to re-capture the failure in a debug log and my scheduled s3cmd syncs don't write debug logs.\r\n\r\nI will try to do another large-scale sync by hand and capture it in a log. Thanks for patience."}}
{"actor":{"display_login":"jblachly"}}