{"action":"created","issue":{"url":"https://api.github.com/repos/ansible/ansible/issues/40013","repository_url":"https://api.github.com/repos/ansible/ansible","labels_url":"https://api.github.com/repos/ansible/ansible/issues/40013/labels{/name}","comments_url":"https://api.github.com/repos/ansible/ansible/issues/40013/comments","events_url":"https://api.github.com/repos/ansible/ansible/issues/40013/events","html_url":"https://github.com/ansible/ansible/issues/40013","id":322308551,"number":40013,"title":"Intermittent Issue: Unable to copy large image files using nxos_file_copy module","user":{"login":"mikewiebe","id":12445795,"avatar_url":"https://avatars2.githubusercontent.com/u/12445795?v=4","gravatar_id":"","url":"https://api.github.com/users/mikewiebe","html_url":"https://github.com/mikewiebe","followers_url":"https://api.github.com/users/mikewiebe/followers","following_url":"https://api.github.com/users/mikewiebe/following{/other_user}","gists_url":"https://api.github.com/users/mikewiebe/gists{/gist_id}","starred_url":"https://api.github.com/users/mikewiebe/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/mikewiebe/subscriptions","organizations_url":"https://api.github.com/users/mikewiebe/orgs","repos_url":"https://api.github.com/users/mikewiebe/repos","events_url":"https://api.github.com/users/mikewiebe/events{/privacy}","received_events_url":"https://api.github.com/users/mikewiebe/received_events","type":"User","site_admin":false},"labels":[{"id":835286067,"url":"https://api.github.com/repos/ansible/ansible/labels/affects_2.6","name":"affects_2.6","color":"ededed","default":false},{"id":785271699,"url":"https://api.github.com/repos/ansible/ansible/labels/bug","name":"bug","color":"fbca04","default":true},{"id":496359346,"url":"https://api.github.com/repos/ansible/ansible/labels/module","name":"module","color":"1d76db","default":false},{"id":339653091,"url":"https://api.github.com/repos/ansible/ansible/labels/networking","name":"networking","color":"c7def8","default":false},{"id":731809659,"url":"https://api.github.com/repos/ansible/ansible/labels/nxos","name":"nxos","color":"c7def8","default":false},{"id":669761792,"url":"https://api.github.com/repos/ansible/ansible/labels/support:network","name":"support:network","color":"ededed","default":false}],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":5,"created_at":"2018-05-11T14:02:33Z","updated_at":"2018-05-22T20:08:30Z","closed_at":null,"author_association":"CONTRIBUTOR","body":"\r\n##### ISSUE TYPE\r\n - Bug Report\r\n\r\n##### COMPONENT NAME\r\nnxos_file_copy\r\n\r\n##### ANSIBLE VERSION\r\n```\r\nansible 2.6.0 (rel260/nxos_upgrade 7bb4da05b6) last updated 2018/05/11 09:14:42 (GMT -400)\r\n  config file = /etc/ansible/ansible.cfg\r\n  configured module search path = [u'/root/.ansible/plugins/modules', u'/usr/share/ansible/plugins/modules']\r\n  ansible python module location = /root/agents-ci/ansible/lib/ansible\r\n  executable location = /root/agents-ci/ansible/bin/ansible\r\n  python version = 2.7.12 (default, Dec  4 2017, 14:50:18) [GCC 5.4.0 20160609]\r\n```\r\n\r\n##### CONFIGURATION\r\n```\r\nDEFAULT_ROLES_PATH(env: ANSIBLE_ROLES_PATH) = [u'/root/agents-ci/ansible/test/integration/targets']\r\nPARAMIKO_HOST_KEY_AUTO_ADD(env: ANSIBLE_PARAMIKO_HOST_KEY_AUTO_ADD) = True\r\nPERSISTENT_COMMAND_TIMEOUT(env: ANSIBLE_PERSISTENT_COMMAND_TIMEOUT) = 600\r\nPERSISTENT_CONNECT_TIMEOUT(env: ANSIBLE_PERSISTENT_CONNECT_TIMEOUT) = 600\r\n```\r\n\r\n##### OS / ENVIRONMENT\r\nUbuntu\r\n\r\n##### SUMMARY\r\nWe used to be able to copy large image files using the `nxos_file_copy` module but now larger files fail to copy with the following error\r\n\r\n```shell\r\n  File \"/usr/local/lib/python2.7/dist-packages/paramiko/transport.py\", line 1610, in _send_user_message\r\n    raise SSHException('Key-exchange timed out waiting for key negotiation')\r\n```\r\n##### STEPS TO REPRODUCE\r\nHere are the image sizes of the files I am trying to copy\r\n\r\nagent-lab9-pm:integration:2053> ls -lh /root/agents_images/\r\ntotal 4.3G\r\n-rw-r--r-- 1 root root  37M Mar  2 11:45 n3000-uk9-kickstart.6.0.2.U6.1a.bin\r\n-rw-r--r-- 1 root root 845M Mar  2 18:42 nxos.7.0.3.I7.2.bin\r\n\r\n```yaml\r\n- name: \"Copy {{ si }} to bootflash\"\r\n  nxos_file_copy:\r\n    local_file: \"{{image_dir}}{{ si }}\"\r\n    file_system: \"bootflash:\"\r\n    provider: \"{{ connection }}\"\r\n  register: result\r\n```\r\n\r\n##### EXPECTED RESULTS\r\nHere is an example using a smaller image file\r\n```shell\r\nTASK [nxos_install_os : Copy n3000-uk9-kickstart.6.0.2.U6.1a.bin to bootflash] *******************************************************************************************************************\r\ntask path: /root/agents-ci/ansible/test/integration/targets/nxos_install_os/tasks/upgrade/copy_kick_system_images.yaml:8\r\n<n9k.example.com> connection transport is cli\r\n<n9k.example.com> using connection plugin network_cli (was local)\r\n<n9k.example.com> starting connection from persistent connection plugin\r\n<n9k.example.com> found existing local domain socket, using it!\r\n<n9k.example.com> updating play_context for connection\r\n<n9k.example.com> \r\n<n9k.example.com> local domain socket path is /root/.ansible/pc/fe6d223170\r\n<n9k.example.com> socket_path: /root/.ansible/pc/fe6d223170\r\nUsing module file /root/agents-ci/ansible/lib/ansible/modules/network/nxos/nxos_file_copy.py\r\n<n9k.example.com> ESTABLISH LOCAL CONNECTION FOR USER: root\r\n<n9k.example.com> EXEC /bin/sh -c 'echo ~root && sleep 0'\r\n<n9k.example.com> EXEC /bin/sh -c '( umask 77 && mkdir -p \"` echo /root/.ansible/tmp/ansible-tmp-1526046585.58-51328088639313 `\" && echo ansible-tmp-1526046585.58-51328088639313=\"` echo /root/.ansible/tmp/ansible-tmp-1526046585.58-51328088639313 `\" ) && sleep 0'\r\n<n9k.example.com> PUT /root/.ansible/tmp/ansible-local-31112XrsRA_/tmpPn8qX7 TO /root/.ansible/tmp/ansible-tmp-1526046585.58-51328088639313/nxos_file_copy.py\r\n<n9k.example.com> EXEC /bin/sh -c 'chmod u+x /root/.ansible/tmp/ansible-tmp-1526046585.58-51328088639313/ /root/.ansible/tmp/ansible-tmp-1526046585.58-51328088639313/nxos_file_copy.py && sleep 0'\r\n<n9k.example.com> EXEC /bin/sh -c '/usr/bin/python /root/.ansible/tmp/ansible-tmp-1526046585.58-51328088639313/nxos_file_copy.py && sleep 0'\r\n<n9k.example.com> EXEC /bin/sh -c 'rm -f -r /root/.ansible/tmp/ansible-tmp-1526046585.58-51328088639313/ > /dev/null 2>&1 && sleep 0'\r\nchanged: [n9k.example.com] => {\r\n    \"changed\": true, \r\n    \"file_system\": \"bootflash:\", \r\n    \"invocation\": {\r\n        \"module_args\": {\r\n            \"auth_pass\": null, \r\n            \"authorize\": null, \r\n            \"connect_ssh_port\": 22, \r\n            \"file_system\": \"bootflash:\", \r\n            \"host\": \"n9k.example.com\", \r\n            \"local_file\": \"/root/agents_images/n3000-uk9-kickstart.6.0.2.U6.1a.bin\", \r\n            \"password\": \"VALUE_SPECIFIED_IN_NO_LOG_PARAMETER\", \r\n            \"port\": null, \r\n            \"provider\": {\r\n                \"auth_pass\": null, \r\n                \"authorize\": null, \r\n                \"host\": \"n9k.example.com\", \r\n                \"password\": \"VALUE_SPECIFIED_IN_NO_LOG_PARAMETER\", \r\n                \"port\": null, \r\n                \"ssh_keyfile\": null, \r\n                \"timeout\": null, \r\n                \"transport\": \"cli\", \r\n                \"use_proxy\": true, \r\n                \"use_ssl\": null, \r\n                \"username\": \"admin\", \r\n                \"validate_certs\": null\r\n            }, \r\n            \"remote_file\": null, \r\n            \"ssh_keyfile\": null, \r\n            \"timeout\": null, \r\n            \"transport\": \"cli\", \r\n            \"use_proxy\": true, \r\n            \"use_ssl\": null, \r\n            \"username\": \"admin\", \r\n            \"validate_certs\": null\r\n        }\r\n    }, \r\n    \"local_file\": \"/root/agents_images/n3000-uk9-kickstart.6.0.2.U6.1a.bin\", \r\n    \"remote_file\": \"n3000-uk9-kickstart.6.0.2.U6.1a.bin\", \r\n    \"transfer_status\": \"Sent\"\r\n}\r\n```\r\n##### ACTUAL RESULTS\r\nHere is an example using a larger image file\r\n```\r\nTASK [nxos_install_os : Copy nxos.7.0.3.I7.2.bin to bootflash] ***********************************************************************************************************************************\r\ntask path: /root/agents-ci/ansible/test/integration/targets/nxos_install_os/tasks/upgrade/copy_kick_system_images.yaml:8\r\n<n9k.example.com> connection transport is cli\r\n<n9k.example.com> using connection plugin network_cli (was local)\r\n<n9k.example.com> starting connection from persistent connection plugin\r\n<n9k.example.com> found existing local domain socket, using it!\r\n<n9k.example.com> updating play_context for connection\r\n<n9k.example.com> \r\n<n9k.example.com> local domain socket path is /root/.ansible/pc/ee1ab4a788\r\n<n9k.example.com> socket_path: /root/.ansible/pc/ee1ab4a788\r\nUsing module file /root/agents-ci/ansible/lib/ansible/modules/network/nxos/nxos_file_copy.py\r\n<n9k.example.com> ESTABLISH LOCAL CONNECTION FOR USER: root\r\n<n9k.example.com> EXEC /bin/sh -c 'echo ~root && sleep 0'\r\n<n9k.example.com> EXEC /bin/sh -c '( umask 77 && mkdir -p \"` echo /root/.ansible/tmp/ansible-tmp-1526046216.79-32071527780141 `\" && echo ansible-tmp-1526046216.79-32071527780141=\"` echo /root/.ansible/tmp/ansible-tmp-1526046216.79-32071527780141 `\" ) && sleep 0'\r\n<n9k.example.com> PUT /root/.ansible/tmp/ansible-local-30569sYjrvT/tmpbMF3OR TO /root/.ansible/tmp/ansible-tmp-1526046216.79-32071527780141/nxos_file_copy.py\r\n<n9k.example.com> EXEC /bin/sh -c 'chmod u+x /root/.ansible/tmp/ansible-tmp-1526046216.79-32071527780141/ /root/.ansible/tmp/ansible-tmp-1526046216.79-32071527780141/nxos_file_copy.py && sleep 0'\r\n<n9k.example.com> EXEC /bin/sh -c '/usr/bin/python /root/.ansible/tmp/ansible-tmp-1526046216.79-32071527780141/nxos_file_copy.py && sleep 0'\r\n<n9k.example.com> EXEC /bin/sh -c 'rm -f -r /root/.ansible/tmp/ansible-tmp-1526046216.79-32071527780141/ > /dev/null 2>&1 && sleep 0'\r\nThe full traceback is:\r\n  File \"/tmp/ansible_HFaPp8/ansible_module_nxos_file_copy.py\", line 174, in transfer_file\r\n    scp.put(module.params['local_file'], full_remote_path)\r\n  File \"/usr/local/lib/python2.7/dist-packages/scp.py\", line 154, in put\r\n    self._send_files(files)\r\n  File \"/usr/local/lib/python2.7/dist-packages/scp.py\", line 249, in _send_files\r\n    chan.sendall(file_hdl.read(buff_size))\r\n  File \"/usr/local/lib/python2.7/dist-packages/paramiko/channel.py\", line 813, in sendall\r\n    sent = self.send(s)\r\n  File \"/usr/local/lib/python2.7/dist-packages/paramiko/channel.py\", line 767, in send\r\n    return self._send(s, m)\r\n  File \"/usr/local/lib/python2.7/dist-packages/paramiko/channel.py\", line 1144, in _send\r\n    self.transport._send_user_message(m)\r\n  File \"/usr/local/lib/python2.7/dist-packages/paramiko/transport.py\", line 1610, in _send_user_message\r\n    raise SSHException('Key-exchange timed out waiting for key negotiation')\r\n\r\nfatal: [n9k.example.com]: FAILED! => {\r\n    \"changed\": false, \r\n    \"file_size\": 885554688, \r\n    \"invocation\": {\r\n        \"module_args\": {\r\n            \"auth_pass\": null, \r\n            \"authorize\": null, \r\n            \"connect_ssh_port\": 22, \r\n            \"file_system\": \"bootflash:\", \r\n            \"host\": \"n9k.example.com\", \r\n            \"local_file\": \"/root/agents_images/nxos.7.0.3.I7.2.bin\", \r\n            \"password\": \"VALUE_SPECIFIED_IN_NO_LOG_PARAMETER\", \r\n            \"port\": null, \r\n            \"provider\": {\r\n                \"auth_pass\": null, \r\n                \"authorize\": null, \r\n                \"host\": \"n9k.example.com\", \r\n                \"password\": \"VALUE_SPECIFIED_IN_NO_LOG_PARAMETER\", \r\n                \"port\": null, \r\n                \"ssh_keyfile\": null, \r\n                \"timeout\": null, \r\n                \"transport\": \"cli\", \r\n                \"use_proxy\": true, \r\n                \"use_ssl\": null, \r\n                \"username\": \"admin\", \r\n                \"validate_certs\": null\r\n            }, \r\n            \"remote_file\": null, \r\n            \"ssh_keyfile\": null, \r\n            \"timeout\": null, \r\n            \"transport\": \"cli\", \r\n            \"use_proxy\": true, \r\n            \"use_ssl\": null, \r\n            \"username\": \"admin\", \r\n            \"validate_certs\": null\r\n        }\r\n    }, \r\n    \"msg\": \"Could not transfer file. There was an error during transfer. Please make sure remote permissions are set.\", \r\n    \"temp_size\": \"534495232\"\r\n}\r\n\tto retry, use: --limit @/root/agents-ci/ansible/test/integration/nxos.retry\r\n\r\nPLAY RECAP ***************************************************************************************************************************************************************************************\r\nn9k.example.com          : ok=41   changed=1    unreachable=0    failed=1 \r\n```\r\n"},"comment":{"url":"https://api.github.com/repos/ansible/ansible/issues/comments/391123654","html_url":"https://github.com/ansible/ansible/issues/40013#issuecomment-391123654","issue_url":"https://api.github.com/repos/ansible/ansible/issues/40013","id":391123654,"user":{"login":"mikewiebe","id":12445795,"avatar_url":"https://avatars2.githubusercontent.com/u/12445795?v=4","gravatar_id":"","url":"https://api.github.com/users/mikewiebe","html_url":"https://github.com/mikewiebe","followers_url":"https://api.github.com/users/mikewiebe/followers","following_url":"https://api.github.com/users/mikewiebe/following{/other_user}","gists_url":"https://api.github.com/users/mikewiebe/gists{/gist_id}","starred_url":"https://api.github.com/users/mikewiebe/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/mikewiebe/subscriptions","organizations_url":"https://api.github.com/users/mikewiebe/orgs","repos_url":"https://api.github.com/users/mikewiebe/repos","events_url":"https://api.github.com/users/mikewiebe/events{/privacy}","received_events_url":"https://api.github.com/users/mikewiebe/received_events","type":"User","site_admin":false},"created_at":"2018-05-22T20:08:30Z","updated_at":"2018-05-22T20:08:30Z","author_association":"CONTRIBUTOR","body":"@gundalow I modified the Exception code to dump the exception but we were already getting it with the verbose mode.  No real additional info here:\r\n\r\n```python\r\n    except Exception, err:\r\n        time.sleep(10)\r\n        temp_size = verify_remote_file_exists(\r\n            module, dest, file_system=module.params['file_system'])\r\n        if int(temp_size) == int(file_size):\r\n            pass\r\n        else:\r\n            msg = 'Could not transfer file. There was an error '\r\n            msg += '\\n %s' % err\r\n            module.fail_json(msg=msg, temp_size=temp_size,\r\n                             file_size=file_size)\r\n```\r\n\r\n```shell\r\nFAILED! => {\"changed\": false, \"file_size\": 759941120, \"msg\": \"Could not transfer file. There was an error \\n Key-exchange timed out waiting for key negotiation\", \"temp_size\": \"489848832\"}\r\n```\r\n\r\nI also increased the timeout but it had no impact.\r\n\r\n```python\r\n    scp = SCPClient(ssh.get_transport(), 500)\r\n```"}}
{"actor":{"display_login":"mikewiebe"}}