search

signalfx / maestro-ng

Orchestration of Docker-based, multi-host environments
https://signalfx.com
Apache License 2.0
682 stars 84 forks source link

Pulling Images fails with Error in _update_pull_progress #204

Open petrkalina opened 5 years ago

petrkalina commented 5 years ago 
petrs-MBP:templates petr$ maestro -f maestro-bug.yaml pull
  #  INSTANCE                                 SERVICE              SHIP                                     CONTAINER                  STATUS    
  1. busybox1                                 busybox              archive                                  failed!
Traceback (most recent call last):
  File "/Library/Python/2.7/site-packages/maestro/__main__.py", line 199, in execute
    getattr(c, options.command)(**vars(options))
  File "/Library/Python/2.7/site-packages/maestro/maestro.py", line 320, in pull
    concurrency, auditor=self.auditor).run()
  File "/Library/Python/2.7/site-packages/maestro/plays/__init__.py", line 160, in run
    self._end()
  File "/Library/Python/2.7/site-packages/maestro/plays/__init__.py", line 148, in _end
    exceptions.raise_with_tb(self._error)
  File "/Library/Python/2.7/site-packages/maestro/plays/__init__.py", line 99, in act
    task.run(auditor=self._auditor)
  File "/Library/Python/2.7/site-packages/maestro/plays/tasks.py", line 103, in run
    exceptions.raise_with_tb()
  File "/Library/Python/2.7/site-packages/maestro/plays/tasks.py", line 95, in run
    self._run()
  File "/Library/Python/2.7/site-packages/maestro/plays/tasks.py", line 481, in _run
    percentage = self._update_pull_progress(dlstatus)
  File "/Library/Python/2.7/site-packages/maestro/plays/tasks.py", line 503, in _update_pull_progress
    last = json.loads(last.decode('utf-8'))
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/json/__init__.py", line 338, in loads
    return _default_decoder.decode(s)
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/json/decoder.py", line 369, in decode
    raise ValueError(errmsg("Extra data", s, end, len(s)))
ValueError: Extra data: line 2 column 1 - line 3 column 1 (char 73 - 145)
petrs-MBP:templates petr$ maestro --version
maestro-ng-0.7.0
petrs-MBP:templates petr$ docker --version
Docker version 18.09.2, build 6247962
petrs-MBP:templates petr$ python --version
Python 2.7.10

the maestro-bug.yam

name: normal

ships:
    archive:
        ip: 127.0.0.1
        timeout: 30
        socket_path: /var/run/docker.sock

services:

    busybox:
        image: busybox
        instances:
            busybox1:
                ship: archive

.. normal docker pull works ok

petrs-MBP:templates petr$ docker pull busybox
Using default tag: latest
latest: Pulling from library/busybox
ee153a04d683: Pull complete 
Digest: sha256:e3b586a669fae4073bb68b5bcabea26dae469ee6f157050c212c77b50f992d5a
Status: Downloaded newer image for busybox:latest
mpetazzoni commented 5 years ago

Hmm, I'm not able to reproduce this problem. Same Maestro version, same Docker version, same environment file. The only difference is that I'm using Python 3.7. Would you be able to test with Python 3 to confirm that this is indeed a Python version issue, with maybe a behavior difference between the json builtin module in 2.7 vs 3.x?

petrkalina commented 5 years ago 
petrs-MacBook-Pro:maestro-ig petr$ maestro -f test.yaml pull  
  #  INSTANCE                                 SERVICE              SHIP                                     CONTAINER                  STATUS    
  1. busybox1                                 busybox              ship1                                    failed!
Traceback (most recent call last):
  File "/Users/petr/Library/Python/2.7/lib/python/site-packages/maestro/__main__.py", line 199, in execute
    getattr(c, options.command)(**vars(options))
  File "/Users/petr/Library/Python/2.7/lib/python/site-packages/maestro/maestro.py", line 320, in pull
    concurrency, auditor=self.auditor).run()
  File "/Users/petr/Library/Python/2.7/lib/python/site-packages/maestro/plays/__init__.py", line 160, in run
    self._end()
  File "/Users/petr/Library/Python/2.7/lib/python/site-packages/maestro/plays/__init__.py", line 148, in _end
    exceptions.raise_with_tb(self._error)
  File "/Users/petr/Library/Python/2.7/lib/python/site-packages/maestro/plays/__init__.py", line 99, in act
    task.run(auditor=self._auditor)
  File "/Users/petr/Library/Python/2.7/lib/python/site-packages/maestro/plays/tasks.py", line 103, in run
    exceptions.raise_with_tb()
  File "/Users/petr/Library/Python/2.7/lib/python/site-packages/maestro/plays/tasks.py", line 95, in run
    self._run()
  File "/Users/petr/Library/Python/2.7/lib/python/site-packages/maestro/plays/tasks.py", line 481, in _run
    percentage = self._update_pull_progress(dlstatus)
  File "/Users/petr/Library/Python/2.7/lib/python/site-packages/maestro/plays/tasks.py", line 503, in _update_pull_progress
    last = json.loads(last.decode('utf-8'))
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/json/__init__.py", line 338, in loads
    return _default_decoder.decode(s)
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/json/decoder.py", line 369, in decode
    raise ValueError(errmsg("Extra data", s, end, len(s)))
ValueError: Extra data: line 2 column 1 - line 4 column 1 (char 186 - 331)
petrs-MacBook-Pro:maestro-ig petr$ python --version
Python 3.7.4
petrs-MacBook-Pro:maestro-ig petr$ maestro --version
maestro-ng-0.7.2
name: test

ships:
    ship1: {ip: 127.0.0.1, timeout: 30, socket_path: /var/run/docker.sock}

services:

    busybox:
        image: busybox
        instances:
            busybox1:
                ship: ship1

I changed python to 3 by i.e.:

echo "alias python=/usr/local/bin/python3" >> ~/.bash_profile

.. I'm not sure how maestro locates the python binary and if it in fact uses the new python3. On my system, the /usr/bin/python still points to python2..

mpetazzoni commented 5 years ago

You're most likely still executing with Python 2.x. When a pip package installs a binary, it embeds the path to the Python executor:

$ head -n1 `which maestro`
#!/opt/boxen/homebrew/Cellar/python/3.7.3/bin/python3.7
petrkalina commented 5 years ago

I think now I'm running python3: 

petrs-MacBook-Pro:templates petr$ sudo pip3 install maestro-ng

...

petrs-MacBook-Pro:templates petr$ maestro --version
maestro-ng-0.7.2

...

petrs-MacBook-Pro:templates petr$ which maestro
/Library/Frameworks/Python.framework/Versions/3.7/bin/maestro

... and finally

petrs-MacBook-Pro:templates petr$ head -n +1 /Library/Frameworks/Python.framework/Versions/3.7/bin/maestro
#!/Library/Frameworks/Python.framework/Versions/3.7/bin/python3.7

but I still get 

petrs-MacBook-Pro:templates petr$ maestro -f archive-psql.yaml pull
  #  INSTANCE                                 SERVICE              SHIP                                     CONTAINER                  STATUS    
  1. ldap1                                    ldap                 archive                                  failed!
Traceback (most recent call last):            archive              archive                                  aborted!
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/__main__.py", line 199, in execute
    getattr(c, options.command)(**vars(options))ycloak             archive                                  aborted!
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/maestro.py", line 320, in pull
    concurrency, auditor=self.auditor).run()
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/plays/__init__.py", line 160, in run
    self._end()
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/plays/__init__.py", line 148, in _end
    exceptions.raise_with_tb(self._error)
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/exceptions.py", line 20, in raise_with_tb
    raise info[1].with_traceback(info[2])
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/plays/__init__.py", line 99, in act
    task.run(auditor=self._auditor)
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/plays/tasks.py", line 103, in run
    exceptions.raise_with_tb()
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/exceptions.py", line 20, in raise_with_tb
    raise info[1].with_traceback(info[2])
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/plays/tasks.py", line 95, in run
    self._run()
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/plays/tasks.py", line 481, in _run
    percentage = self._update_pull_progress(dlstatus)
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/plays/tasks.py", line 503, in _update_pull_progress
    last = json.loads(last.decode('utf-8'))
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/json/__init__.py", line 348, in loads
    return _default_decoder.decode(s)
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/json/decoder.py", line 340, in decode
    raise JSONDecodeError("Extra data", s, end)
json.decoder.JSONDecodeError: Extra data: line 2 column 1 (char 94)
petrkalina commented 5 years ago

I looked around and found taht this may be something between docker and docker-py - see https://github.com/docker/docker-py/issues/1059 - it might have been resolved already..

mpetazzoni commented 5 years ago

So maybe run pip3 install --upgrade docker-py and retry?

mpetazzoni commented 5 years ago

If that fixes it, it might mean I have to set a minimum version requirement for docker-py in my requirements.txt file.

petrkalina commented 5 years ago

it seems the library is on recent version:

petrs-MacBook-Pro:~ petr$ pip3 install --upgrade docker-py
Requirement already up-to-date: docker-py in /Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages (1.10.6)
Requirement already satisfied, skipping upgrade: six>=1.4.0 in /Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages (from docker-py) (1.12.0)
Requirement already satisfied, skipping upgrade: requests!=2.11.0,>=2.5.2 in /Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages (from docker-py) (2.22.0)
Requirement already satisfied, skipping upgrade: docker-pycreds>=0.2.1 in /Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages (from docker-py) (0.4.0)
Requirement already satisfied, skipping upgrade: websocket-client>=0.32.0 in /Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages (from docker-py) (0.56.0)
Requirement already satisfied, skipping upgrade: urllib3!=1.25.0,!=1.25.1,<1.26,>=1.21.1 in /Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages (from requests!=2.11.0,>=2.5.2->docker-py) (1.25.6)
Requirement already satisfied, skipping upgrade: idna<2.9,>=2.5 in /Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages (from requests!=2.11.0,>=2.5.2->docker-py) (2.8)
Requirement already satisfied, skipping upgrade: chardet<3.1.0,>=3.0.2 in /Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages (from requests!=2.11.0,>=2.5.2->docker-py) (3.0.4)
Requirement already satisfied, skipping upgrade: certifi>=2017.4.17 in /Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages (from requests!=2.11.0,>=2.5.2->docker-py) (2019.9.11)
You are using pip version 19.0.3, however version 19.3 is available.
You should consider upgrading via the 'pip install --upgrade pip' command.

the stacktrace also points towards python 3:

petrs-MacBook-Pro:templates petr$ maestro -f archive-psql.yaml pull
  #  INSTANCE                                 SERVICE              SHIP                                     CONTAINER                  STATUS    
  1. ldap1                                    ldap                 archive                                  failed!
  2. archive1                                 archive              archive                                  waiting...
  3. keycloak1                                keycloak             archive                                  waiting...
Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/__main__.py", line 199, in execute
    getattr(c, options.command)(**vars(options))ycloak             archive                                  aborted!
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/maestro.py", line 320, in pull
    concurrency, auditor=self.auditor).run()
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/plays/__init__.py", line 160, in run
    self._end()
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/plays/__init__.py", line 148, in _end
    exceptions.raise_with_tb(self._error)
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/exceptions.py", line 20, in raise_with_tb
    raise info[1].with_traceback(info[2])
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/plays/__init__.py", line 99, in act
    task.run(auditor=self._auditor)
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/plays/tasks.py", line 103, in run
    exceptions.raise_with_tb()
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/exceptions.py", line 20, in raise_with_tb
    raise info[1].with_traceback(info[2])
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/plays/tasks.py", line 95, in run
    self._run()
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/plays/tasks.py", line 481, in _run
    percentage = self._update_pull_progress(dlstatus)
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/site-packages/maestro/plays/tasks.py", line 503, in _update_pull_progress
    last = json.loads(last.decode('utf-8'))
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/json/__init__.py", line 348, in loads
    return _default_decoder.decode(s)
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/json/decoder.py", line 340, in decode
    raise JSONDecodeError("Extra data", s, end)
json.decoder.JSONDecodeError: Extra data: line 2 column 1 (char 94)
petrkalina commented 5 years ago

I found out that currently the issue does NOT appear when pulling from default docker registry i.e.:

services:

    busybox:
        image: busybox
        instances:
            busybox1:
                ship: archive

...

petrs-MacBook-Pro:templates petr$ maestro -f /tmp/test.yaml pull  
  #  INSTANCE                                 SERVICE              SHIP                                     CONTAINER                  STATUS    
  1. busybox1                                 busybox              archive                                                             done

however, it still occurs against our private registry. I don't know how do I extract the exact version of the API from the registry, all I can see is:

$ curl -vk https://localhost:443/v2/
> GET /v2/ HTTP/1.1
> Host: localhost
> User-Agent: curl/7.47.0
> Accept: */*
> 
< HTTP/1.1 401 Unauthorized
< Content-Type: application/json; charset=utf-8
< Docker-Distribution-Api-Version: registry/2.0
...

... i.e. the API is v2 (Docker-Distribution-Api-Version: registry/2.0). The image is running several months though, so it may not be the latest API..

petrkalina commented 4 years ago

was able to reproduce on fresh install:

name: normal

ships:
    test:
        ip: {ship-addr}
        timeout: 30

services:

    test:
        image: docker.j4care.com/busybox
        instances:
            test1:
                ship: test

$ maestro -f test.yaml pull test1
  #  INSTANCE             SERVICE              SHIP           CONTAINER                  STATUS
  1. test1                test                 test           failed!
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/maestro/__main__.py", line 206, in execute
    getattr(c, options.command)(**vars(options))
  File "/usr/local/lib/python3.6/site-packages/maestro/maestro.py", line 336, in pull
    concurrency, auditor=self.auditor).run()
  File "/usr/local/lib/python3.6/site-packages/maestro/plays/__init__.py", line 160, in run
    self._end()
  File "/usr/local/lib/python3.6/site-packages/maestro/plays/__init__.py", line 148, in _end
    exceptions.raise_with_tb(self._error)
  File "/usr/local/lib/python3.6/site-packages/maestro/exceptions.py", line 20, in raise_with_tb
    raise info[1].with_traceback(info[2])
  File "/usr/local/lib/python3.6/site-packages/maestro/plays/__init__.py", line 99, in act
    task.run(auditor=self._auditor)
  File "/usr/local/lib/python3.6/site-packages/maestro/plays/tasks.py", line 103, in run
    exceptions.raise_with_tb()
  File "/usr/local/lib/python3.6/site-packages/maestro/exceptions.py", line 20, in raise_with_tb
    raise info[1].with_traceback(info[2])
  File "/usr/local/lib/python3.6/site-packages/maestro/plays/tasks.py", line 95, in run
    self._run()
  File "/usr/local/lib/python3.6/site-packages/maestro/plays/tasks.py", line 518, in _run
    percentage = self._update_pull_progress(dlstatus)
  File "/usr/local/lib/python3.6/site-packages/maestro/plays/tasks.py", line 540, in _update_pull_progress
    last = json.loads(last.decode('utf-8'))
  File "/usr/lib64/python3.6/json/__init__.py", line 354, in loads
    return _default_decoder.decode(s)
  File "/usr/lib64/python3.6/json/decoder.py", line 342, in decode
    raise JSONDecodeError("Extra data", s, end)
json.decoder.JSONDecodeError: Extra data: line 2 column 1 (char 49)

however:

$ docker -H {ship-addr} pull docker.j4care.com/busybox
Using default tag: latest
latest: Pulling from busybox
aab39f0bc16d: Already exists
a3ed95caeb02: Already exists
Digest: sha256:dafbf6c075f915201d2d427584b751434ab0ba2e3dd3e2c149ad8440ce5d4f1e
Status: Image is up to date for docker.j4care.com/busybox:latest
docker.j4care.com/busybox:latest

docker:

$ docker --version
Docker version 19.03.8, build afacb8b

python: 

$ python --version
Python 2.7.5

$ python3 --version
Python 3.6.8

py-docker:

$ sudo pip3 install --upgrade docker-py
Requirement already up-to-date: docker-py in /usr/local/lib/python3.6/site-packages

I cannot test access to docker default registry, as it is not allowed by the proxy at the moment. I will add this later when I can test this..