apt_key very slow on some keys?

Archives Ansible Project
1

Hello,

I am playing around with ansible and I wanted to use apt_key.

You can see in the picture on the left pane, that it takes 7 minutes to just add the postgresql key with apt_key.

1912×1048 102 KB

Whereas when I use the url to a key (the key which is used in the ansible docs), the module is quite fast and it takes only 3 seconds to add the key.

1912×1048 103 KB

What is the difference between those keys? Why does it give me “changed=1” in the first example and “changed=0” in the second case?
Is it anyhow related to this github issue: https://github.com/ansible/ansible/issues/10091 ?
With the url https://download.docker.com/linux/ubuntu/gpg …it is not working at all. (after plenty of minutes- maybe 20 minutes - the ssh connection aborts)

Has anybody some experience with this?
My ansible version is 2.5.1, just in case it matters.

Thank you in advance!

2

Hard to say from this information.
What do your plays look like?

(attachments)

Auto Generated Inline Image 1.png
Auto Generated Inline Image 1.png1912×1048 102 KB

Auto Generated Inline Image 2.png
Auto Generated Inline Image 2.png1912×1048 103 KB

3

The play in the pane on the bottom right.

It is just this in the file test_task.yml:

<<

4

It must be something in your environment, it only takes 4 seconds here

$ ansible-playbook --version
ansible-playbook 2.5.1

$ ANSIBLE_CALLBACK_WHITELIST=timer ansible-playbook apt.yml -K
SUDO password:

PLAY [localhost]

5

Thank for trying! Thats interesting.

Apparently there is a problem with my virtualbox ubuntu server.

I tried the play on real hardware and it worked just fine with all of the three key urls.

In a newly installed virtualbox ubuntu server the problem persists. So I guess it has to do something with the keys…

My systems on the hardware and in the virtualbox are both Ubuntu 18.04.

Any other hints? How could I track this down? Would this need to “debug” the underlaying python?

6

If you know Python the easiest is probably setting ANSIBLE_KEEP_REMOTE_FILES=1 [1] and then run the python script manually.
Running it with cProfile [2] you could easy find where it spends the time.

[1] https://docs.ansible.com/ansible/latest/dev_guide/debugging.html#debugging-remote
[2] https://docs.python.org/2/library/profile.html

7

Thanks for those hints. I tried to debug the problem.
Here are two outputs of the cProfile runs:
https://drive.google.com/drive/folders/12Kvtl1ic0yt7V0spZHP-mZJuq7XxN3OY?usp=sharing
One is with the key url that is very fast, the other is the one, that works very slow.

Here the section of the very slow cProfile url run:

1 0.001 0.001 1129.126 1129.126 ansible_module_apt_key.py:11(<module>) 1 0.000 0.000 1128.953 1128.953 ansible_module_apt_key.py:270(main) 1 0.000 0.000 1128.500 1128.500 ansible_module_apt_key.py:207(download_key) 1 0.000 0.000 1128.500 1128.500 urls.py:954(fetch_url) 1 0.000 0.000 1128.500 1128.500 urls.py:782(open_url) 1 0.000 0.000 1128.498 1128.498 urllib2.py:131(urlopen) 1 0.001 0.001 1128.498 1128.498 urllib2.py:411(open) 2 0.000 0.000 1128.401 564.201 socket.py:541(create_connection) 38 0.000 0.000 1128.366 29.694 socket.py:227(meth) 18 1128.366 62.687 1128.366 62.687 {method 'connect' of '_socket.socket' objects} 1 0.000 0.000 1048.343 1048.343 urls.py:669(http_request) 1 0.000 0.000 80.153 80.153 urllib2.py:439(_open) 2 0.000 0.000 80.153 40.077 urllib2.py:399(_call_chain) 1 0.000 0.000 80.153 80.153 urls.py:334(https_open) 1 0.000 0.000 80.153 80.153 urllib2.py:1152(do_open) 1 0.000 0.000 80.138 80.138 httplib.py:1040(request) 1 0.000 0.000 80.138 80.138 httplib.py:1067(_send_request) 1 0.000 0.000 80.138 80.138 httplib.py:1025(endheaders) 1 0.000 0.000 80.138 80.138 httplib.py:867(_send_output) 1 0.000 0.000 80.138 80.138 httplib.py:840(send) 1 0.000 0.000 80.138 80.138 urls.py:308(connect)

Where is the difference between connecting to

url: https://ftp-master.debian.org/keys/archive-key-6.0.asc
and
url: https://download.docker.com/linux/ubuntu/gpg

?

8

I have done some additional debugging.
Here is where the python almost hangs up with the “slow url”:

1912×1048 101 KB

And here the same for the “fast url”:

1912×1048 72.5 KB

Is it possible, that it has to do something with the IP in conjunction with the virtualbox? IPv4 vs IPv6?

My virtualbox network setting is set to “bridged networking”.

Is it maybe this bug I am facing: https://www.virtualbox.org/ticket/5503 ?

I feel this is not the right place to proceed with this debugging?
Should I get in contact with the virtualbox developers or with a python developer?

9

I think I can confirm now, that it is a problem with the IPv6 adress.

I just used the proposal from https://stackoverflow.com/questions/31519567/disable-ipv6-for-python-script and changed /etc/gai.conf.
Python now connects to “99.84.92.59” instead of the IPv6 adress “2600:9000:200d:a000:3:db06:4200:93a1”.

The Playbook took on the virtualbox ubuntu server with this setting around 3 seconds.

10

Although this make things work, there still is something off in your
network configuration, as the OS for some reason thinks it has IPv6
connectivity, tries to use that, and then fails.
On a vanilla Bionic64 VM with working IPv6 this works instantly, so
the general IPv6 connectivity of download.docker.com looks to be fine.