After upgrading our setup (on all machines) from Python2 to Python3, non-binary file transfer with cp.push and cp.push_dir from (all) Windows minions to the Ubuntu master is failing.
$ grep recv /etc/salt/master
file_recv: True
file_recv_max_size: 1000
$ locale
LANG=en_US.UTF-8
LANGUAGE=en_US
LC_CTYPE="en_US.UTF-8"
LC_NUMERIC="en_US.UTF-8"
LC_TIME="en_US.UTF-8"
LC_COLLATE="en_US.UTF-8"
LC_MONETARY="en_US.UTF-8"
LC_MESSAGES="en_US.UTF-8"
LC_PAPER="en_US.UTF-8"
LC_NAME="en_US.UTF-8"
LC_ADDRESS="en_US.UTF-8"
LC_TELEPHONE="en_US.UTF-8"
LC_MEASUREMENT="en_US.UTF-8"
LC_IDENTIFICATION="en_US.UTF-8"
LC_ALL=en_US.UTF-8
md5-08887b0de4811b79ccea4c4f5ed60181
[DEBUG ] Reading configuration from /etc/salt/master
[DEBUG ] Using cached minion ID from /etc/salt/minion_id: ##################
[DEBUG ] Missing configuration file: /root/.saltrc
[DEBUG ] Configuration file path: /etc/salt/master
[WARNING ] Insecure logging configuration detected! Sensitive data may be logged.
[DEBUG ] Reading configuration from /etc/salt/master
[DEBUG ] Using cached minion ID from /etc/salt/minion_id: ##################
[DEBUG ] Missing configuration file: /root/.saltrc
[DEBUG ] MasterEvent PUB socket URI: /var/run/salt/master/master_event_pub.ipc
[DEBUG ] MasterEvent PULL socket URI: /var/run/salt/master/master_event_pull.ipc
[DEBUG ] Initializing new AsyncZeroMQReqChannel for (u'/etc/salt/pki/master', u'##################', u'tcp://127.0.0.1:4506', u'clear')
[DEBUG ] Connecting the Minion to the Master URI (for the return server): tcp://127.0.0.1:4506
[DEBUG ] Trying to connect to: tcp://127.0.0.1:4506
[DEBUG ] Initializing new IPCClient for path: /var/run/salt/master/master_event_pub.ipc
[DEBUG ] LazyLoaded local_cache.get_load
[DEBUG ] Reading minion list from /var/cache/salt/master/jobs/41/56f4bfbc0ae20061e1e24511e9e1198404e35c181a189ce2b9fbd518175fec/.minions.p
[DEBUG ] get_iter_returns for jid 20180528135422884137 sent to set(['Win-7-Reference']) will timeout at 13:54:27.906454
[DEBUG ] Checking whether jid 20180528135422884137 is still running
[DEBUG ] Initializing new AsyncZeroMQReqChannel for (u'/etc/salt/pki/master', u'##################', u'tcp://127.0.0.1:4506', u'clear')
[DEBUG ] Connecting the Minion to the Master URI (for the return server): tcp://127.0.0.1:4506
[DEBUG ] Trying to connect to: tcp://127.0.0.1:4506
[DEBUG ] Passing on saltutil error. Key 'u'retcode' missing from client return. This may be an error in the client.
[DEBUG ] jid 20180528135422884137 return from Win-7-Reference
[DEBUG ] return event: {u'Win-7-Reference': {u'jid': u'20180528135422884137', u'retcode': 0, u'ret': u'C:\salt\salt.ico'}}
[DEBUG ] LazyLoaded nested.output
Win-7-Reference:
C:\salt\salt.ico
[DEBUG ] jid 20180528135422884137 found all minions set([u'Win-7-Reference'])
```bash
salt '*' cp.push C:\\salt\\salt.ico upload_path='salt.ico'
[DEBUG ] Reading configuration from /etc/salt/master
[DEBUG ] Using cached minion ID from /etc/salt/minion_id: ##################
[DEBUG ] Missing configuration file: /root/.saltrc
[DEBUG ] Configuration file path: /etc/salt/master
[WARNING ] Insecure logging configuration detected! Sensitive data may be logged.
[DEBUG ] Reading configuration from /etc/salt/master
[DEBUG ] Using cached minion ID from /etc/salt/minion_id: ##################
[DEBUG ] Missing configuration file: /root/.saltrc
[DEBUG ] MasterEvent PUB socket URI: /var/run/salt/master/master_event_pub.ipc
[DEBUG ] MasterEvent PULL socket URI: /var/run/salt/master/master_event_pull.ipc
[DEBUG ] Initializing new AsyncZeroMQReqChannel for (u'/etc/salt/pki/master', u'##################', u'tcp://127.0.0.1:4506', u'clear')
[DEBUG ] Connecting the Minion to the Master URI (for the return server): tcp://127.0.0.1:4506
[DEBUG ] Trying to connect to: tcp://127.0.0.1:4506
[DEBUG ] Initializing new IPCClient for path: /var/run/salt/master/master_event_pub.ipc
[DEBUG ] LazyLoaded local_cache.get_load
[DEBUG ] Reading minion list from /var/cache/salt/master/jobs/6a/3fbd7491c121971f422945fcdd2b6dae60dac0c6a13845f91508d43a4fcc99/.minions.p
[DEBUG ] get_iter_returns for jid 20180528133843500298 sent to set(['Win-7-Reference']) will timeout at 13:38:48.521387
[DEBUG ] Checking whether jid 20180528133843500298 is still running
[DEBUG ] Initializing new AsyncZeroMQReqChannel for (u'/etc/salt/pki/master', u'##################', u'tcp://127.0.0.1:4506', u'clear')
[DEBUG ] Connecting the Minion to the Master URI (for the return server): tcp://127.0.0.1:4506
[DEBUG ] Trying to connect to: tcp://127.0.0.1:4506
[DEBUG ] Passing on saltutil error. Key 'u'retcode' missing from client return. This may be an error in the client.
[DEBUG ] jid 20180528133843500298 return from Win-7-Reference
[DEBUG ] return event: {u'Win-7-Reference': {u'jid': u'20180528133843500298', u'retcode': 0, u'ret': True}}
[DEBUG ] LazyLoaded nested.output
Win-7-Reference:
True
[DEBUG ] jid 20180528133843500298 found all minions set([u'Win-7-Reference'])
md5-4267698023f7832e12546dbe363c0598
[DEBUG ] Reading configuration from /etc/salt/master
[DEBUG ] Using cached minion ID from /etc/salt/minion_id: ##################
[DEBUG ] Missing configuration file: /root/.saltrc
[DEBUG ] Configuration file path: /etc/salt/master
[WARNING ] Insecure logging configuration detected! Sensitive data may be logged.
[DEBUG ] Reading configuration from /etc/salt/master
[DEBUG ] Using cached minion ID from /etc/salt/minion_id: ##################
[DEBUG ] Missing configuration file: /root/.saltrc
[DEBUG ] MasterEvent PUB socket URI: /var/run/salt/master/master_event_pub.ipc
[DEBUG ] MasterEvent PULL socket URI: /var/run/salt/master/master_event_pull.ipc
[DEBUG ] Initializing new AsyncZeroMQReqChannel for (u'/etc/salt/pki/master', u'##################', u'tcp://127.0.0.1:4506', u'clear')
[DEBUG ] Connecting the Minion to the Master URI (for the return server): tcp://127.0.0.1:4506
[DEBUG ] Trying to connect to: tcp://127.0.0.1:4506
[DEBUG ] Initializing new IPCClient for path: /var/run/salt/master/master_event_pub.ipc
[DEBUG ] LazyLoaded local_cache.get_load
[DEBUG ] Reading minion list from /var/cache/salt/master/jobs/b9/e3a53eb1f7ff49b71d7e13f77a73048d51566739b68c30df6e721e9675d1c4/.minions.p
[DEBUG ] get_iter_returns for jid 20180528135826683842 sent to set(['Win-7-Reference']) will timeout at 13:58:31.705204
[DEBUG ] Checking whether jid 20180528135826683842 is still running
[DEBUG ] Initializing new AsyncZeroMQReqChannel for (u'/etc/salt/pki/master', u'##################', u'tcp://127.0.0.1:4506', u'clear')
[DEBUG ] Connecting the Minion to the Master URI (for the return server): tcp://127.0.0.1:4506
[DEBUG ] Trying to connect to: tcp://127.0.0.1:4506
[DEBUG ] Passing on saltutil error. Key 'u'retcode' missing from client return. This may be an error in the client.
[DEBUG ] jid 20180528135826683842 return from Win-7-Reference
[DEBUG ] return event: {u'Win-7-Reference': {u'jid': u'20180528135826683842', u'retcode': 0, u'ret': u'C:\salt\salt-minion.bat'}}
[DEBUG ] LazyLoaded nested.output
Win-7-Reference:
C:\salt\salt-minion.bat
[DEBUG ] jid 20180528135826683842 found all minions set([u'Win-7-Reference'])
#### Faulty
```bash
salt '*' cp.push C:\\salt\\salt-minion.bat upload_path='salt-minion.bat'
master
[DEBUG ] Reading configuration from /etc/salt/master
[DEBUG ] Using cached minion ID from /etc/salt/minion_id: ##################
[DEBUG ] Missing configuration file: /root/.saltrc
[DEBUG ] Configuration file path: /etc/salt/master
[WARNING ] Insecure logging configuration detected! Sensitive data may be logged.
[DEBUG ] Reading configuration from /etc/salt/master
[DEBUG ] Using cached minion ID from /etc/salt/minion_id: ##################
[DEBUG ] Missing configuration file: /root/.saltrc
[DEBUG ] MasterEvent PUB socket URI: /var/run/salt/master/master_event_pub.ipc
[DEBUG ] MasterEvent PULL socket URI: /var/run/salt/master/master_event_pull.ipc
[DEBUG ] Initializing new AsyncZeroMQReqChannel for (u'/etc/salt/pki/master', u'##################', u'tcp://127.0.0.1:4506', u'clear')
[DEBUG ] Connecting the Migrep recv /etc/salt/master
file_recv: True
file_recv_max_size: 1000nion to the Master URI (for the return server): tcp://127.0.0.1:4506
[DEBUG ] Trying to connect to: tcp://127.0.0.1:4506
[DEBUG ] Initializing new IPCClient for path: /var/run/salt/master/master_event_pub.ipc
[DEBUG ] LazyLoaded local_cache.get_load
[DEBUG ] Reading minion list from /var/cache/salt/master/jobs/0c/51516ebe52b3964e928b85530846221cdfb7f8265fb60d3704445f5c177449/.minions.p
[DEBUG ] get_iter_returns for jid 20180528134100384505 sent to set(['Win-7-Reference']) will timeout at 13:41:05.405971
[DEBUG ] Checking whether jid 20180528134100384505 is still running
[DEBUG ] Initializing new AsyncZeroMQReqChannel for (u'/etc/salt/pki/master', u'##################, u'tcp://127.0.0.1:4506', u'clear')
[DEBUG ] Connecting the Minion to the Master URI (for the return server): tcp://127.0.0.1:4506
[DEBUG ] Trying to connect to: tcp://127.0.0.1:4506
[DEBUG ] Passing on saltutil error. Key 'u'retcode' missing from client return. This may be an error in the client.
[DEBUG ] jid 20180528134100384505 return from Win-7-Reference
[DEBUG ] return event: {u'Win-7-Reference': {u'jid': u'20180528134100384505', u'retcode': 0, u'ret': u''}}
[DEBUG ] LazyLoaded nested.output
Win-7-Reference:
[DEBUG ] jid 20180528134100384505 found all minions set([u'Win-7-Reference'])
From journalctl on master:
```Mai 28 13:35:41 ################## salt-master[20485]: [ERROR ] Error in function _file_recv:
Mai 28 13:35:41 ################## salt-master[20485]: Traceback (most recent call last):
Mai 28 13:35:41 ################## salt-master[20485]: File "/data/##################/anaconda3/lib/python3.6/site-packages/salt/master.py", line 1776, in run_func
Mai 28 13:35:41 ################## salt-master[20485]: ret = getattr(self, func)(load)
Mai 28 13:35:41 ################## salt-master[20485]: File "/data/##################/anaconda3/lib/python3.6/site-packages/salt/master.py", line 1454, in _file_recv
Mai 28 13:35:41 ################## salt-master[20485]: fp_.write(load['data'])
Mai 28 13:35:41 ################## salt-master[20485]: TypeError: a bytes-like object is required, not 'str'
minion
[INFO ] User sudo_################## Executing command cp.push with jid 20180528140813551877
[DEBUG ] Command details {'ret': '', 'jid': '20180528140813551877', 'arg': ['C:\salt\salt-minion.bat', {'upload_path': 'salt-minion.bat', '__kwarg__': True}], 'tgt_type': 'glob', 'user': 'sudo_##################', 'tgt': 'Win-7*', 'fun': 'cp.push'}
[DEBUG ] Multiprocessing queue logging configured for the process running under PID: 4172
[DEBUG ] Grains refresh requested. Refreshing grains.
[DEBUG ] Reading configuration from c:\salt\confminion
[DEBUG ] Including configuration from 'c:\salt\confminion.d_schedule.conf'
[DEBUG ] Reading configuration from c:\salt\confminion.d_schedule.conf
[INFO ] User sudo_################## Executing command saltutil.find_job with jid 20180528140818682145
[DEBUG ] Command details {'ret': '', 'jid': '20180528140818682145', 'arg': ['20180528140813551877'], 'tgt_type': 'list', 'user': 'sudo_##################', 'tgt': ['Win-7-Reference'], 'fun': 'saltutil.find_job'}
[DEBUG ] Multiprocessing queue logging configured for the process running under PID: 5592
[DEBUG ] Grains refresh requested. Refreshing grains.
[DEBUG ] Reading configuration from c:\salt\confminion
[DEBUG ] Including configuration from 'c:\salt\confminion.d_schedule.conf'
[DEBUG ] Reading configuration from c:\salt\confminion.d_schedule.conf
[INFO ] Creating minion process manager
[INFO ] Starting a new job with PID 4172
[DEBUG ] LazyLoaded cp.push
[DEBUG ] LazyLoaded direct_call.execute
[DEBUG ] Trying to copy 'C:\salt\salt-minion.bat' to master
[DEBUG ] Initializing new SAuth for ('c:\salt\conf\pki\minion', 'Win-7-Reference', 'tcp://##################:4506')
[DEBUG ] salt.crypt.get_rsa_key: Loading private key
[DEBUG ] salt.crypt._get_key_with_evict: Loading private key
[DEBUG ] Loaded minion key: c:\salt\conf\pkiminionminion.pem
[DEBUG ] Popen(['git', 'version'], cwd=C:\salt, universal_newlines=False, shell=None)
[DEBUG ] Initializing new AsyncZeroMQReqChannel for ('c:\salt\conf\pki\minion', 'Win-7-Reference', 'tcp://##################:4506', 'aes')
[DEBUG ] Initializing new AsyncAuth for ('c:\salt\conf\pki\minion', 'Win-7-Reference', 'tcp://##################:4506')
[DEBUG ] Connecting the Minion to the Master URI (for the return server): tcp://##################:4506
[DEBUG ] Trying to connect to: tcp://##################:4506
[DEBUG ] Initializing new AsyncZeroMQReqChannel for ('c:\salt\conf\pki\minion', 'Win-7-Reference', 'tcp://##################:4506', 'clear')
[DEBUG ] Connecting the Minion to the Master URI (for the return server): tcp://##################:4506
[DEBUG ] Trying to connect to: tcp://##################:4506
[DEBUG ] salt.crypt.get_rsa_pub_key: Loading public key
[DEBUG ] Decrypting the current master AES key
[DEBUG ] salt.crypt.get_rsa_key: Loading private key
[DEBUG ] Loaded minion key: c:\salt\conf\pkiminionminion.pem
[DEBUG ] salt.crypt.get_rsa_pub_key: Loading public key
[ERROR ] cp.push Failed transfer failed. Ensure master has 'file_recv' set to 'True' and that the file is not larger than the 'file_recv_size_max' setting on the master.
[DEBUG ] Minion return retry timer set to 9 seconds (randomized)
[INFO ] Returning information for job: 20180528140813551877
[DEBUG ] Initializing new AsyncZeroMQReqChannel for ('c:\salt\conf\pki\minion', 'Win-7-Reference', 'tcp://##################:4506', 'aes')
[DEBUG ] Initializing new AsyncAuth for ('c:\salt\conf\pki\minion', 'Win-7-Reference', 'tcp://##################:4506')
[DEBUG ] Connecting the Minion to the Master URI (for the return server): tcp://##################:4506
[DEBUG ] Trying to connect to: tcp://##################:4506
[INFO ] Creating minion process manager
[INFO ] Starting a new job with PID 5592
[DEBUG ] LazyLoaded saltutil.find_job
[DEBUG ] LazyLoaded direct_call.execute
[DEBUG ] Minion return retry timer set to 5 seconds (randomized)
[INFO ] Returning information for job: 20180528140818682145
[DEBUG ] Popen(['git', 'version'], cwd=C:\salt, universal_newlines=False, shell=None)
[DEBUG ] Initializing new AsyncZeroMQReqChannel for ('c:\salt\conf\pki\minion', 'Win-7-Reference', 'tcp://##################:4506', 'aes')
[DEBUG ] Initializing new AsyncAuth for ('c:\salt\conf\pki\minion', 'Win-7-Reference', 'tcp://##################:4506')
[DEBUG ] Connecting the Minion to the Master URI (for the return server): tcp://##################:4506
[DEBUG ] Trying to connect to: tcp://##################:4506
[DEBUG ] Initializing new AsyncZeroMQReqChannel for ('c:\salt\conf\pki\minion', 'Win-7-Reference', 'tcp://##################:4506', 'clear')
[DEBUG ] Connecting the Minion to the Master URI (for the return server): tcp://##################:4506
[DEBUG ] Trying to connect to: tcp://##################:4506
[DEBUG ] salt.crypt.get_rsa_pub_key: Loading public key
[DEBUG ] Decrypting the current master AES key
[DEBUG ] salt.crypt.get_rsa_key: Loading private key
[DEBUG ] salt.crypt._get_key_with_evict: Loading private key
[DEBUG ] Loaded minion key: c:\salt\conf\pkiminionminion.pem
[DEBUG ] salt.crypt.get_rsa_pub_key: Loading public key
### Versions Report
master
Salt Version:
Salt: 2018.3.0
Dependency Versions:
cffi: 1.11.4
cherrypy: Not Installed
dateutil: 2.6.1
docker-py: Not Installed
gitdb: Not Installed
gitpython: Not Installed
ioflo: Not Installed
Jinja2: 2.10
libgit2: Not Installed
libnacl: Not Installed
M2Crypto: Not Installed
Mako: Not Installed
msgpack-pure: Not Installed
msgpack-python: 0.5.6
mysql-python: Not Installed
pycparser: 2.18
pycrypto: 2.6.1
pycryptodome: Not Installed
pygit2: Not Installed
Python: 3.6.4 |Anaconda, Inc.| (default, Jan 16 2018, 18:10:19)
python-gnupg: Not Installed
PyYAML: 3.12
PyZMQ: 17.0.0
RAET: Not Installed
smmap: Not Installed
timelib: Not Installed
Tornado: 4.5.3
ZMQ: 4.1.6
System Versions:
dist: debian stretch/sid
locale: utf8
machine: x86_64
release: 4.4.0-124-lowlatency
system: Linux
version: debian stretch/sid
minion
Salt Version:
Salt: 2018.3.0
Dependency Versions:
cffi: 1.10.0
cherrypy: 10.2.1
dateutil: 2.6.1
docker-py: Not Installed
gitdb: 2.0.3
gitpython: Not Installed
ioflo: Not Installed
Jinja2: 2.10
libgit2: Not Installed
libnacl: Not Installed
M2Crypto: Not Installed
Mako: 1.0.7
msgpack-pure: Not Installed
msgpack-python: 0.4.8
mysql-python: Not Installed
pycparser: 2.18
pycrypto: 2.6.1
pycryptodome: Not Installed
pygit2: Not Installed
Python: 3.5.3 (v3.5.3:1880cb95a742, Jan 16 2017, 16:02:32) [MSC v.1900 64 bit (AMD64)]
python-gnupg: 0.4.1
PyYAML: 3.12
PyZMQ: 16.0.3
RAET: Not Installed
smmap: 2.0.3
timelib: 0.2.4
Tornado: 4.5.2
ZMQ: 4.1.6
System Versions:
dist:
locale: cp1252
machine: AMD64
release: 7
system: Windows
version: 7 6.1.7601 SP1 Multiprocessor Free
```
@twangboy @dwoz Thoughts?
I just tried replicating this on my system and it all worked fine... no matter the version of Python on the Windows box. My master was on Py2. I see you're using Python 3.6 on your master. Maybe it has something to do with that.
I can confirm that this problem exists in any Python3.6 installations using Salt v2018.3.0 (and presumably earlier) -- not just Windows.
I did a quick fix to https://github.com/saltstack/salt/blob/v2018.3.0/salt/master.py#L1454
by converting to a bytearray
...and then discovered that this fix had already been applied here https://github.com/saltstack/salt/blob/v2018.3.1/salt/master.py#L1454
:1st_place_medal: :1st_place_medal: :1st_place_medal:
Thank you for the update, @edlane!
We'll try deployment with v2018.3.1 as soon as there is time for it.
After pulling and installing the release tagged v2018.3.1 from Github, I can confirm that the failure is gone. All posted commands execute successfully, even the cp.push that previously failed.
Thanks for confirming @C0nsultant! I'll go ahead and close this.