saltstack / salt

Software to automate the management and configuration of any infrastructure or application at scale. Install Salt from the Salt package repositories here:
https://docs.saltproject.io/salt/install-guide/en/latest/
Apache License 2.0
14.22k stars 5.49k forks source link

[BUG] salt-call pkg.install using proxy generates UnicodeDecodeError #60908

Open bsoldhogg opened 3 years ago

bsoldhogg commented 3 years ago

Description I'm testing a masterless Windows minion in an environment that must use a proxy to get out to the internet. During a pkg.install run, the minion attempts to download the package but it runs in to an unhandled exception for UnicodeDecodeError which ultimately results in an endless loop. Only when I kill the salt-call operation do I see the connection in the proxy logs.

This behaviour is not seen with a masterless minion in a different environment that doesn't require a proxy.

Setup

Salt minion config (C:\salt\conf\minion.d\masterless.conf)

winrepo_dir_ng: 'C:\Temp\packages'
file_client: local
file_roots:
  base:
    - 'C:\Temp\saltconf'
    - 'C:\Temp\packages'
proxy_host: http://[REDACTED]
proxy_port: 3128

Test state to achieve a download of an installer (C:\Temp\packages\win\repo-ng\datadog-pkg.sls)

datadog-pkg:
  'latest':
    installer: https://s3.amazonaws.com/ddagent-windows-stable/datadog-agent-7-latest.amd64.msi
    full_name: Datadog Agent
    reboot: False
    install_flags: '/qn'
    msiexec: True

Debug output

C:\Users\Administrator>salt-call pkg.install datadog-pkg -l debug
[DEBUG   ] Reading configuration from c:\salt\conf\minion
[DEBUG   ] Including configuration from 'c:\salt\conf\minion.d\masterless.conf'
[DEBUG   ] Reading configuration from c:\salt\conf\minion.d\masterless.conf
[DEBUG   ] Using cached minion ID from c:\salt\conf\minion_id: [REDACTED]
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Override  __grains__: <module 'salt.loaded.int.log_handlers.sentry_mod' from 'c:\\salt\\bin\\lib\\site-packages\\salt-3003.3-py3.7.egg\\salt\\log\\handlers\\sentry_mod.py'>
[DEBUG   ] Configuration file path: c:\salt\conf\minion
[WARNING ] Insecure logging configuration detected! Sensitive data may be logged.
[DEBUG   ] Grains refresh requested. Refreshing grains.
[DEBUG   ] Reading configuration from c:\salt\conf\minion
[DEBUG   ] Including configuration from 'c:\salt\conf\minion.d\masterless.conf'
[DEBUG   ] Reading configuration from c:\salt\conf\minion.d\masterless.conf
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Override  __utils__: <module 'salt.loaded.int.grains.zfs' from 'c:\\salt\\bin\\lib\\site-packages\\salt-3003.3-py3.7.egg\\salt\\grains\\zfs.py'>
[DEBUG   ] Motherboard info not available on this system
[DEBUG   ] Determining pillar cache
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] LazyLoaded jinja.render
[DEBUG   ] LazyLoaded yaml.render
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] LazyLoaded jinja.render
[DEBUG   ] LazyLoaded yaml.render
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] LazyLoaded pkg.install
[DEBUG   ] LazyLoaded direct_call.execute
[DEBUG   ] LazyLoaded path.which
[DEBUG   ] Override  __salt__: <module 'salt.loaded.int.module.dracr' from 'c:\\salt\\bin\\lib\\site-packages\\salt-3003.3-py3.7.egg\\salt\\modules\\dracr.py'>
[DEBUG   ] Override  __grains__: <module 'salt.loaded.int.module.grains' from 'c:\\salt\\bin\\lib\\site-packages\\salt-3003.3-py3.7.egg\\salt\\modules\\grains.py'>
[DEBUG   ] Missing configuration file: /etc/salt/minion
[DEBUG   ] Using cached minion ID from c:\salt\conf\minion_id: [REDACTED]
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Popen(['git', 'version'], cwd=C:\Users\Administrator, universal_newlines=False, shell=None, istream=None)
[DEBUG   ] Popen(['git', 'version'], cwd=C:\Users\Administrator, universal_newlines=False, shell=None, istream=None)
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Could not LazyLoad idem.hub: 'idem' __virtual__ returned False: No module named 'pop'
[DEBUG   ] Override  __salt__: <module 'salt.loaded.int.module.kubeadm' from 'c:\\salt\\bin\\lib\\site-packages\\salt-3003.3-py3.7.egg\\salt\\modules\\kubeadm.py'>
[DEBUG   ] Override  __salt__: <module 'salt.loaded.int.module.udev' from 'c:\\salt\\bin\\lib\\site-packages\\salt-3003.3-py3.7.egg\\salt\\modules\\udev.py'>
[DEBUG   ] Override  __pillar__: <module 'salt.loaded.int.module.virtualenv_mod' from 'c:\\salt\\bin\\lib\\site-packages\\salt-3003.3-py3.7.egg\\salt\\modules\\virtualenv_mod.py'>
[DEBUG   ] Could not LazyLoad pkg.normalize_name: 'pkg.normalize_name' is not available.
[DEBUG   ] Using existing pkg metadata db for saltenv 'base' (age is 0:44:53.550253)
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] Using pkg_resources to load entry points
[DEBUG   ] LazyLoaded roots.envs
[DEBUG   ] Could not LazyLoad roots.init: 'roots.init' is not available.
[DEBUG   ] Updating roots fileserver cache
[DEBUG   ] Requesting URL https://s3.amazonaws.com/ddagent-windows-stable/datadog-agent-7-latest.amd64.msi using GET method
[DEBUG   ] Using backend: tornado
[DEBUG   ] GET https://s3.amazonaws.com/ddagent-windows-stable/datadog-agent-7-latest.amd64.msi
[DEBUG   ] Trying [REDACTED]:3128...
[DEBUG   ] TCP_NODELAY set
[DEBUG   ] Connected to proxy ([REDACTED]) port 3128 (#0)
[DEBUG   ] allocate connect buffer!
[DEBUG   ] Establish HTTP proxy tunnel to s3.amazonaws.com:443
[DEBUG   ] > CONNECT s3.amazonaws.com:443 HTTP/1.1
[DEBUG   ] > Host: s3.amazonaws.com:443
[DEBUG   ] > User-Agent: Mozilla/5.0 (compatible; pycurl)
[DEBUG   ] > Proxy-Connection: Keep-Alive
[DEBUG   ] >
[DEBUG   ] < HTTP/1.1 200 Connection established
[DEBUG   ] <
[DEBUG   ] Proxy replied 200 to CONNECT request
[DEBUG   ] CONNECT phase completed!
[DEBUG   ] ALPN, offering h2
[DEBUG   ] ALPN, offering http/1.1
[DEBUG   ] successfully set certificate verify locations:
[DEBUG   ] CAfile: c:\salt\bin\lib\site-packages\certifi\cacert.pem
  CApath: none
[DEBUG   ] TLSv1.3 (OUT), TLS handshake, Client hello (1):
[ERROR   ] An un-handled exception was caught by salt's global exception handler:
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xfc in position 3: invalid start byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xfc in position 3: invalid start byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xfc in position 3: invalid start byte
[DEBUG   ] CONNECT phase completed!
[DEBUG   ] CONNECT phase completed!
[DEBUG   ] TLSv1.3 (IN), TLS handshake, Server hello (2):
[ERROR   ] An un-handled exception was caught by salt's global exception handler:
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xb7 in position 8: invalid start byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xb7 in position 8: invalid start byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xb7 in position 8: invalid start byte
[ERROR   ] An un-handled exception was caught by salt's global exception handler:
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xfc in position 4: invalid start byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xfc in position 4: invalid start byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xfc in position 4: invalid start byte
[DEBUG   ] TLSv1.2 (IN), TLS handshake, Certificate (11):
[ERROR   ] An un-handled exception was caught by salt's global exception handler:
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xf8 in position 3: invalid start byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xf8 in position 3: invalid start byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xf8 in position 3: invalid start byte
[DEBUG   ] TLSv1.2 (IN), TLS handshake, Server key exchange (12):
[ERROR   ] An un-handled exception was caught by salt's global exception handler:
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xed in position 10: invalid continuation byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xed in position 10: invalid continuation byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xed in position 10: invalid continuation byte
[DEBUG   ] TLSv1.2 (IN), TLS handshake, Server finished (14):
[DEBUG   ] TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
[ERROR   ] An un-handled exception was caught by salt's global exception handler:
UnicodeDecodeError: 'utf-8' codec can't decode byte 0x89 in position 9: invalid start byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0x89 in position 9: invalid start byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0x89 in position 9: invalid start byte
[DEBUG   ] TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):
[DEBUG   ] TLSv1.2 (OUT), TLS handshake, Finished (20):
[ERROR   ] An un-handled exception was caught by salt's global exception handler:
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xf6 in position 6: invalid start byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xf6 in position 6: invalid start byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xf6 in position 6: invalid start byte
[DEBUG   ] TLSv1.2 (IN), TLS handshake, Finished (20):
[ERROR   ] An un-handled exception was caught by salt's global exception handler:
UnicodeDecodeError: 'utf-8' codec can't decode byte 0x89 in position 4: invalid start byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0x89 in position 4: invalid start byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0x89 in position 4: invalid start byte
[DEBUG   ] SSL connection using TLSv1.2 / ECDHE-RSA-AES128-GCM-SHA256
[DEBUG   ] ALPN, server did not agree to a protocol
[DEBUG   ] Server certificate:
[DEBUG   ] subject: C=US; ST=Washington; L=Seattle; O=Amazon.com, Inc.; CN=s3.amazonaws.com
[DEBUG   ] start date: Jun 23 00:00:00 2021 GMT
[DEBUG   ] expire date: Jul 24 23:59:59 2022 GMT
[DEBUG   ] subjectAltName: host "s3.amazonaws.com" matched cert's "s3.amazonaws.com"
[DEBUG   ] issuer: C=US; O=DigiCert Inc; OU=www.digicert.com; CN=DigiCert Baltimore CA-2 G2
[DEBUG   ] SSL certificate verify ok.
[ERROR   ] An un-handled exception was caught by salt's global exception handler:
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xc3 in position 4: unexpected end of data
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xc3 in position 4: unexpected end of data
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xc3 in position 4: unexpected end of data
[DEBUG   ] > GET /ddagent-windows-stable/datadog-agent-7-latest.amd64.msi HTTP/1.1
[DEBUG   ] > Host: s3.amazonaws.com
[DEBUG   ] > Accept: */*
[DEBUG   ] > Accept-Encoding: none
[DEBUG   ] > User-Agent: Salt/3003.3 http.query()
[DEBUG   ] >
[ERROR   ] An un-handled exception was caught by salt's global exception handler:
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xc1 in position 4: invalid start byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xc1 in position 4: invalid start byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xc1 in position 4: invalid start byte
[DEBUG   ] Mark bundle as not supporting multiuse
[DEBUG   ] < HTTP/1.1 200 OK
[DEBUG   ] < x-amz-id-2: ShWwCUuw2QKOhy17QDd/c+w74FCtjD177B9uJYgGEg8CxreY0sE1nDF4XztPdhiJN2sVLz8cdxY=
[DEBUG   ] < x-amz-request-id: SW8T6H404RRMQBE5
[DEBUG   ] < Date: Tue, 21 Sep 2021 14:42:10 GMT
[DEBUG   ] < Last-Modified: Mon, 13 Sep 2021 10:14:34 GMT
[DEBUG   ] < ETag: "9baec09fb5b739123662453779c0d22c-22"
[DEBUG   ] < x-amz-version-id: tNXfoB6p0zqWSd0PmJ.gsQ.9gALyNScV
[DEBUG   ] < Accept-Ranges: bytes
[DEBUG   ] < Content-Type: application/x-msi
[DEBUG   ] < Server: AmazonS3
[DEBUG   ] < Content-Length: 184336384
[DEBUG   ] <
[ERROR   ] An un-handled exception was caught by salt's global exception handler:
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xd0 in position 0: invalid continuation byte
Traceback (most recent call last):
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "c:\salt\bin\lib\site-packages\salt-3003.3-py3.7.egg\salt\ext\tornado\escape.py", line 219, in to_unicode
    return value.decode("utf-8")

Steps to Reproduce the behavior This behaviour can be reproduced with any installer, no matter if it's hosted on S3 or not. I'm not able to test without using a proxy on EC2 but I have tested in a VMware environment that doesn't require a proxy, with the same minion config (minus proxy settings), states and packages copied over as is, and there is no issue.

Powershell is able to use wget to download installers from the internet using environment proxy settings.

Expected behavior I expect Salt to be able to retrieve packages from the internet with proxy settings configured in the minion, just as it does without.

Versions Report

C:\Users\Administrator>salt-call test.versions
local:
    Salt Version:
              Salt: 3003.3

    Dependency Versions:
              cffi: 1.14.5
          cherrypy: 18.6.0
          dateutil: 2.8.1
         docker-py: Not Installed
             gitdb: 4.0.5
         gitpython: Not Installed
            Jinja2: 2.11.3
           libgit2: Not Installed
          M2Crypto: Not Installed
              Mako: 1.1.4
           msgpack: 1.0.2
      msgpack-pure: Not Installed
      mysql-python: Not Installed
         pycparser: 2.20
          pycrypto: Not Installed
      pycryptodome: 3.9.8
            pygit2: Not Installed
            Python: 3.7.4 (tags/v3.7.4:e09359112e, Jul  8 2019, 20:34:20) [MSC v.1916 64 bit (AMD64)]
      python-gnupg: 0.4.6
            PyYAML: 5.4.1
             PyZMQ: 18.0.1
             smmap: 3.0.4
           timelib: 0.2.4
           Tornado: 4.5.3
               ZMQ: 4.3.1

    System Versions:
              dist:
            locale: cp1252
           machine: AMD64
           release: 2019Server
            system: Windows
           version: 2019Server 10.0.17763 SP0

p3lim commented 2 years ago

Seeing the same with 3003.3 (latest on Fedora) and a HTTP(S) proxy, although with a master. I'm not seeing an endless loop however, it just spams this message with thousands of lines in the logs causing rotations to occur multiple time per highstate.

There is no functional issue for us, but we've had to place the salt-minion's logs in a blocklist on our log aggregator due to all the noise wasting our license quotas.

eliasp commented 2 years ago

Seeing it on 3005 when downloading binary files via a proxy.

How to reproduce (there might be a more straightforward way, I'm just mostly replicating what I'm running here for $reasons):

  1. Start a local socks proxy:
     ssh -D 1080 localhost 'while true; do echo "$(date) Keep the proxy alive..."; sleep 5; done'
  2. Start a SOCKS5 to HTTP proxy (Salt doesn't support SOCKS5, only plain HTTP proxies):
    • Build s2h: go install github.com/mritd/s2h@master
    • Run s2h:
      $ s2h
      INFO[2022-27-24 15:31:08] Starting Socks5 Proxy Convert Server...
      INFO[2022-27-24 15:31:08] HTTP Listen Address: 0.0.0.0:8081
      INFO[2022-27-24 15:31:08] Socks5 Server Address: 127.0.0.1:1080
  3. Configure Salt to use this proxy by adding those lines to the Minion configuration:
     proxy_host: localhost
     proxy_port: 8081
  4. Let Salt download a binary file through this proxy:
     salt-call --local cp.get_url https://docs.saltproject.io/en/pdf/Salt-3005.pdf /tmp/Salt-3005.pdf

The result is: thousands of times this error repeated:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/salt/ext/tornado/curl_httpclient.py", line 497, in _curl_debug
    debug_msg = native_str(debug_msg)
  File "/usr/lib/python3/dist-packages/salt/ext/tornado/escape.py", line 219, in to_unicode
    return value.decode("utf-8")
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xf4 in position 1: invalid continuation byte

It works fine for non-binary files, e.g.:

salt-call --local cp.get_url https://saltproject.io/wp-content/uploads/2020/12/main-logo.svg /tmp/main-logo.svg
local:
    /tmp/main-logo.svg

Version Report:

Salt Version:
          Salt: 3005

Dependency Versions:
          cffi: Not Installed
      cherrypy: Not Installed
      dateutil: 2.7.3
     docker-py: Not Installed
         gitdb: Not Installed
     gitpython: Not Installed
        Jinja2: 2.10.1
       libgit2: Not Installed
      M2Crypto: Not Installed
          Mako: Not Installed
       msgpack: 0.6.2
  msgpack-pure: Not Installed
  mysql-python: Not Installed
     pycparser: Not Installed
      pycrypto: Not Installed
  pycryptodome: 3.6.1
        pygit2: Not Installed
        Python: 3.8.10 (default, Jun 22 2022, 20:18:18)
  python-gnupg: 0.4.5
        PyYAML: 5.3.1
         PyZMQ: 18.1.1
         smmap: Not Installed
       timelib: Not Installed
       Tornado: 4.5.3
           ZMQ: 4.3.2

System Versions:
          dist: ubuntu 20.04 focal
        locale: utf-8
       machine: x86_64
       release: 5.4.0-88-generic
        system: Linux
       version: Ubuntu 20.04 focal
eliasp commented 2 years ago

After finding https://github.com/tornadoweb/tornado/issues/1608 which was fixed in d7d9c467cda38f4c9352172ba7411edc29a85196, I followed the same approach and hot-fixed it here by doing this:

diff --git a/usr/lib/python3/dist-packages/salt/ext/tornado/curl_httpclient.py.orig b/usr/lib/python3/dist-packages/salt/ext/tornado/curl_httpclient.py
index 8652343..6ef3349 100644
--- a/usr/lib/python3/dist-packages/salt/ext/tornado/curl_httpclient.py.orig
+++ b/usr/lib/python3/dist-packages/salt/ext/tornado/curl_httpclient.py
@@ -494,7 +494,7 @@ class CurlAsyncHTTPClient(AsyncHTTPClient):

     def _curl_debug(self, debug_type, debug_msg):
         debug_types = ('I', '<', '>', '<', '>')
-        debug_msg = native_str(debug_msg)
+        debug_msg = native_str(debug_msg.decode('latin1'))
         if debug_type == 0:
             curl_log.debug('%s', debug_msg.strip())
         elif debug_type in (1, 2):

I'll have to look into making sure this fix is addressed properly upstream - will follow up here...

eliasp commented 2 years ago

As Salt ships a bundled Tornado curl_httpclient.py, it might be sufficient until upstream addresses this issue (https://github.com/tornadoweb/tornado/issues/3183) to apply the diff from my previous comment...