Improve time to run playbook

[pushcx]

With no changes to deploy, running time ansible-playbook -K prod.yml reports that ansible takes 7m22.602s.

Even running just the lobsters rle to deploy site tweaks with pushcx@gingham:~/code/lobsters takes 3m57.459s.

This is a significant pain point for me. Iterating on improvement to the playbook has a huge pause where I'm tempted to go read twitter and never come back, and running just the lobsters role has left changes to other playbooks undeployed.

I enabled ssh pipelining in e7bfa94 but it's not enough. I don't understand what ansible is doing that a no-change run of the playbook takes more than a few seconds to run when only a handful of the commands it runs takes a half-second. I feel like I'm missing something obvious and hope someone can contribute suggestions for how to investigate or improve this.

[PhilArmstrong]

https://github.com/jlafon/ansible-profile looks helpful

[pushcx]

With the ssh config I added we've slightly reduced runtime to 6m20.001s.

Here's a run with profiling enabled. The closing summary looks like the biggest timesinks are running apt-get, copying files, and repeatedly gathering facts. Let me reiterate that this is a run with no changes, no packages are added or removed, no files have been added or edited, etc.

PLAY [mariadb] *************************************************************************************************************************************************************************************

TASK [Gathering Facts] *****************************************************************************************************************************************************************************
Wednesday 09 May 2018  09:28:01 -0500 (0:00:00.029)       0:00:00.029 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [systype : set_fact arch, family, platform] ***************************************************************************************************************************************************
Wednesday 09 May 2018  09:28:07 -0500 (0:00:06.158)       0:00:06.188 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [mariadb : include_tasks] *********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:28:09 -0500 (0:00:01.097)       0:00:07.285 ********* 
included: /home/pushcx/code/l-ansible/roles/mariadb/tasks/apt.yml for lobsters.xen.prgmr.com

TASK [mariadb : apt-get install mariadb] ***********************************************************************************************************************************************************
Wednesday 09 May 2018  09:28:09 -0500 (0:00:00.036)       0:00:07.322 ********* 
ok: [lobsters.xen.prgmr.com] => (item=[u'mariadb-server'])

TASK [mariadb : include_tasks] *********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:28:14 -0500 (0:00:05.823)       0:00:13.146 ********* 
skipping: [lobsters.xen.prgmr.com]

TASK [mariadb : mariadb config files] **************************************************************************************************************************************************************
Wednesday 09 May 2018  09:28:14 -0500 (0:00:00.024)       0:00:13.171 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [mariadb : Enable mariadb at startup] *********************************************************************************************************************************************************
Wednesday 09 May 2018  09:28:52 -0500 (0:00:37.128)       0:00:50.299 ********* 
ok: [lobsters.xen.prgmr.com]

PLAY [unicorn] *************************************************************************************************************************************************************************************

TASK [Gathering Facts] *****************************************************************************************************************************************************************************
Wednesday 09 May 2018  09:28:54 -0500 (0:00:02.047)       0:00:52.346 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [systype : set_fact arch, family, platform] ***************************************************************************************************************************************************
Wednesday 09 May 2018  09:28:59 -0500 (0:00:05.386)       0:00:57.733 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [unicorn : include_tasks] *********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:29:00 -0500 (0:00:01.266)       0:00:58.999 ********* 
included: /home/pushcx/code/l-ansible/roles/unicorn/tasks/apt.yml for lobsters.xen.prgmr.com

TASK [unicorn : apt-get install unicorn] ***********************************************************************************************************************************************************
Wednesday 09 May 2018  09:29:00 -0500 (0:00:00.034)       0:00:59.034 ********* 
ok: [lobsters.xen.prgmr.com] => (item=[u'unicorn'])

TASK [unicorn : include_tasks] *********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:29:06 -0500 (0:00:05.539)       0:01:04.573 ********* 
skipping: [lobsters.xen.prgmr.com]

TASK [unicorn : lobsters directory] ****************************************************************************************************************************************************************
Wednesday 09 May 2018  09:29:06 -0500 (0:00:00.023)       0:01:04.596 ********* 
ok: [lobsters.xen.prgmr.com] => (item=http)
ok: [lobsters.xen.prgmr.com] => (item=run)
ok: [lobsters.xen.prgmr.com] => (item=log)

TASK [unicorn : copy up unicorn config] ************************************************************************************************************************************************************
Wednesday 09 May 2018  09:29:10 -0500 (0:00:04.324)       0:01:08.921 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [unicorn : copy unicorn systemd service config] ***********************************************************************************************************************************************
Wednesday 09 May 2018  09:29:16 -0500 (0:00:05.376)       0:01:14.298 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [unicorn : just force systemd to reread configs] **********************************************************************************************************************************************
Wednesday 09 May 2018  09:29:20 -0500 (0:00:04.230)       0:01:18.529 ********* 
ok: [lobsters.xen.prgmr.com]

PLAY [lobsters] ************************************************************************************************************************************************************************************

TASK [Gathering Facts] *****************************************************************************************************************************************************************************
Wednesday 09 May 2018  09:29:24 -0500 (0:00:03.942)       0:01:22.471 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [systype : set_fact arch, family, platform] ***************************************************************************************************************************************************
Wednesday 09 May 2018  09:29:31 -0500 (0:00:07.166)       0:01:29.637 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [lobsters : include_tasks] ********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:29:32 -0500 (0:00:01.313)       0:01:30.951 ********* 
included: /home/pushcx/code/l-ansible/roles/lobsters/tasks/apt.yml for lobsters.xen.prgmr.com

TASK [lobsters : apt-get install lobsters dependencies] ********************************************************************************************************************************************
Wednesday 09 May 2018  09:29:32 -0500 (0:00:00.035)       0:01:30.987 ********* 
ok: [lobsters.xen.prgmr.com] => (item=[u'cmake', u'g++', u'gcc', u'git', u'libc-dev', u'libmysqlclient-dev', u'libsqlite3-dev', u'make', u'mariadb-client', u'nodejs', u'ruby2.3', u'ruby2.3-dev', u'sqlite3'])

TASK [lobsters : include_tasks] ********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:29:38 -0500 (0:00:05.588)       0:01:36.575 ********* 
skipping: [lobsters.xen.prgmr.com]

TASK [lobsters : groupadd lobsters] ****************************************************************************************************************************************************************
Wednesday 09 May 2018  09:29:38 -0500 (0:00:00.023)       0:01:36.599 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [lobsters : useradd lobsters] *****************************************************************************************************************************************************************
Wednesday 09 May 2018  09:29:39 -0500 (0:00:00.734)       0:01:37.334 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [lobsters : mkdir ~lobste.rs/.%] **************************************************************************************************************************************************************
Wednesday 09 May 2018  09:29:41 -0500 (0:00:02.155)       0:01:39.489 ********* 
ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'02700', u'file': u'ssh'})

TASK [lobsters : cp % ~lobsters/.%] ****************************************************************************************************************************************************************
Wednesday 09 May 2018  09:29:43 -0500 (0:00:01.867)       0:01:41.357 ********* 
ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0600', u'file': u'ssh/known_hosts'})

TASK [lobsters : git clone lobsters] ***************************************************************************************************************************************************************
Wednesday 09 May 2018  09:29:47 -0500 (0:00:03.982)       0:01:45.340 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [lobsters : check if bundler needs installing] ************************************************************************************************************************************************
Wednesday 09 May 2018  09:29:49 -0500 (0:00:02.433)       0:01:47.774 ********* 
changed: [lobsters.xen.prgmr.com]

TASK [lobsters : install bundler] ******************************************************************************************************************************************************************
Wednesday 09 May 2018  09:29:51 -0500 (0:00:01.786)       0:01:49.560 ********* 
changed: [lobsters.xen.prgmr.com]

TASK [lobsters : bundle install] *******************************************************************************************************************************************************************
Wednesday 09 May 2018  09:30:06 -0500 (0:00:14.867)       0:02:04.428 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [lobsters : migrate database] *****************************************************************************************************************************************************************
Wednesday 09 May 2018  09:30:08 -0500 (0:00:02.791)       0:02:07.219 ********* 
skipping: [lobsters.xen.prgmr.com]

TASK [lobsters : copy templates and icons] *********************************************************************************************************************************************************
Wednesday 09 May 2018  09:30:09 -0500 (0:00:00.020)       0:02:07.240 ********* 
ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0600', u'file': u'app'})
ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0644', u'file': u'public'})

TASK [lobsters : recompile assets] *****************************************************************************************************************************************************************
Wednesday 09 May 2018  09:30:54 -0500 (0:00:45.275)       0:02:52.515 ********* 
skipping: [lobsters.xen.prgmr.com]

TASK [lobsters : restart unicorn] ******************************************************************************************************************************************************************
Wednesday 09 May 2018  09:30:54 -0500 (0:00:00.020)       0:02:52.535 ********* 
skipping: [lobsters.xen.prgmr.com]

TASK [lobsters : cp cron script] *******************************************************************************************************************************************************************
Wednesday 09 May 2018  09:30:54 -0500 (0:00:00.019)       0:02:52.555 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [lobsters : add crontab entry] ****************************************************************************************************************************************************************
Wednesday 09 May 2018  09:30:58 -0500 (0:00:04.139)       0:02:56.695 ********* 
ok: [lobsters.xen.prgmr.com]

PLAY [nginx] ***************************************************************************************************************************************************************************************

TASK [Gathering Facts] *****************************************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:00 -0500 (0:00:01.877)       0:02:58.572 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [systype : set_fact arch, family, platform] ***************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:05 -0500 (0:00:05.293)       0:03:03.866 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [nginx : include_tasks] ***********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:06 -0500 (0:00:01.293)       0:03:05.160 ********* 
included: /home/pushcx/code/l-ansible/roles/nginx/tasks/apt.yml for lobsters.xen.prgmr.com

TASK [nginx : apt-get install nginx] ***************************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:06 -0500 (0:00:00.047)       0:03:05.207 ********* 
ok: [lobsters.xen.prgmr.com] => (item=[u'nginx'])

TASK [nginx : include_tasks] ***********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:18 -0500 (0:00:11.700)       0:03:16.907 ********* 
skipping: [lobsters.xen.prgmr.com]

PLAY [postfix] *************************************************************************************************************************************************************************************

TASK [Gathering Facts] *****************************************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:18 -0500 (0:00:00.029)       0:03:16.937 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [systype : set_fact arch, family, platform] ***************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:23 -0500 (0:00:04.509)       0:03:21.447 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [postfix : include_tasks] *********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:24 -0500 (0:00:01.321)       0:03:22.768 ********* 
included: /home/pushcx/code/l-ansible/roles/postfix/tasks/apt.yml for lobsters.xen.prgmr.com

TASK [postfix : apt-get install postfix] ***********************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:24 -0500 (0:00:00.033)       0:03:22.802 ********* 
ok: [lobsters.xen.prgmr.com] => (item=[u'opendkim', u'postfix'])

TASK [postfix : include_tasks] *********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:31 -0500 (0:00:06.605)       0:03:29.407 ********* 
skipping: [lobsters.xen.prgmr.com]

TASK [postfix : cp /etc/default/opendkim] **********************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:31 -0500 (0:00:00.023)       0:03:29.430 ********* 
ok: [lobsters.xen.prgmr.com] => (item={u'name': u'etc/default/opendkim', u'mode': u'0644'})
ok: [lobsters.xen.prgmr.com] => (item={u'name': u'etc/opendkim.conf', u'mode': u'0644'})

TASK [postfix : cp /etc/aliases] *******************************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:37 -0500 (0:00:06.660)       0:03:36.091 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [postfix : cp /etc/postfix] *******************************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:41 -0500 (0:00:03.743)       0:03:39.834 ********* 
ok: [lobsters.xen.prgmr.com] => (item={u'name': u'main.cf', u'mode': u'0644'})
ok: [lobsters.xen.prgmr.com] => (item={u'name': u'master.cf', u'mode': u'0644'})
ok: [lobsters.xen.prgmr.com] => (item={u'name': u'transport', u'mode': u'0644'})

TASK [postfix : postmap] ***************************************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:53 -0500 (0:00:11.553)       0:03:51.387 ********* 
skipping: [lobsters.xen.prgmr.com]

TASK [postfix : postfix reload] ********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:53 -0500 (0:00:00.020)       0:03:51.408 ********* 
skipping: [lobsters.xen.prgmr.com]

PLAY [sysadm] **************************************************************************************************************************************************************************************

TASK [Gathering Facts] *****************************************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:53 -0500 (0:00:00.026)       0:03:51.434 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [systype : set_fact arch, family, platform] ***************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:58 -0500 (0:00:04.967)       0:03:56.401 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [sysadm : include_tasks] **********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:59 -0500 (0:00:01.535)       0:03:57.937 ********* 
included: /home/pushcx/code/l-ansible/roles/sysadm/tasks/apt.yml for lobsters.xen.prgmr.com

TASK [sysadm : apt-get install sysadm dependencies] ************************************************************************************************************************************************
Wednesday 09 May 2018  09:31:59 -0500 (0:00:00.035)       0:03:57.973 ********* 
ok: [lobsters.xen.prgmr.com] => (item=[u'fail2ban', u'ksh', u'locate', u'nvi', u'tmux'])

TASK [sysadm : include_tasks] **********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:32:04 -0500 (0:00:05.021)       0:04:02.994 ********* 
skipping: [lobsters.xen.prgmr.com]

TASK [sysadm : include sudo supplementary group] ***************************************************************************************************************************************************
Wednesday 09 May 2018  09:32:04 -0500 (0:00:00.029)       0:04:03.023 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [sysadm : include_tasks] **********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:32:04 -0500 (0:00:00.055)       0:04:03.079 ********* 
included: /home/pushcx/code/l-ansible/roles/sysadm/tasks/a.yml for lobsters.xen.prgmr.com

TASK [sysadm : groupadd a] *************************************************************************************************************************************************************************
Wednesday 09 May 2018  09:32:04 -0500 (0:00:00.036)       0:04:03.116 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [sysadm : useradd a] **************************************************************************************************************************************************************************
Wednesday 09 May 2018  09:32:05 -0500 (0:00:00.676)       0:04:03.793 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [sysadm : add a's ssh keys] *******************************************************************************************************************************************************************
Wednesday 09 May 2018  09:32:07 -0500 (0:00:01.878)       0:04:05.671 ********* 
ok: [lobsters.xen.prgmr.com] => (item={u'file': u'a-20171001.pub'})

TASK [sysadm : cp dot,a ~a] ************************************************************************************************************************************************************************
Wednesday 09 May 2018  09:32:10 -0500 (0:00:02.680)       0:04:08.352 ********* 
ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'bashrc'})
ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'dcrc'})
ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'exrc'})
ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'inputrc'})
ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'kshrc'})
ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'nexrc'})
ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'profile'})
ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'tmux.conf'})
ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'vimrc'})

TASK [sysadm : rm dot,a ~a/] ***********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:32:45 -0500 (0:00:34.954)       0:04:43.307 ********* 
ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'bash_logout'})
ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'bash_profile'})

TASK [sysadm : include_tasks] **********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:32:48 -0500 (0:00:03.653)       0:04:46.960 ********* 
included: /home/pushcx/code/l-ansible/roles/sysadm/tasks/pushcx.yml for lobsters.xen.prgmr.com

TASK [sysadm : groupadd pushcx] ********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:32:48 -0500 (0:00:00.030)       0:04:46.990 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [sysadm : useradd pushcx] *********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:32:50 -0500 (0:00:01.889)       0:04:48.879 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [sysadm : add pushcx's ssh keys] **************************************************************************************************************************************************************
Wednesday 09 May 2018  09:32:52 -0500 (0:00:02.210)       0:04:51.090 ********* 
ok: [lobsters.xen.prgmr.com] => (item={u'file': u'pushcx-20171001.pub'})

PLAY [tarsnap] *************************************************************************************************************************************************************************************

TASK [Gathering Facts] *****************************************************************************************************************************************************************************
Wednesday 09 May 2018  09:32:56 -0500 (0:00:03.153)       0:04:54.244 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [systype : set_fact arch, family, platform] ***************************************************************************************************************************************************
Wednesday 09 May 2018  09:33:01 -0500 (0:00:05.313)       0:04:59.557 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : include_tasks] *********************************************************************************************************************************************************************
Wednesday 09 May 2018  09:33:02 -0500 (0:00:00.957)       0:05:00.515 ********* 
included: /home/pushcx/code/l-ansible/roles/tarsnap/tasks/apt.yml for lobsters.xen.prgmr.com

TASK [tarsnap : copy up tarsnap key] ***************************************************************************************************************************************************************
Wednesday 09 May 2018  09:33:02 -0500 (0:00:00.046)       0:05:00.561 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : add tarsnap key] *******************************************************************************************************************************************************************
Wednesday 09 May 2018  09:33:07 -0500 (0:00:05.149)       0:05:05.710 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : add tarsnap repo] ******************************************************************************************************************************************************************
Wednesday 09 May 2018  09:33:10 -0500 (0:00:03.495)       0:05:09.206 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : apt-get install tarsnap] ***********************************************************************************************************************************************************
Wednesday 09 May 2018  09:33:13 -0500 (0:00:02.061)       0:05:11.268 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : apt-get install logrotate] *********************************************************************************************************************************************************
Wednesday 09 May 2018  09:33:18 -0500 (0:00:05.425)       0:05:16.693 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : copy up logrotate and tarsnap configs] *********************************************************************************************************************************************
Wednesday 09 May 2018  09:33:23 -0500 (0:00:04.910)       0:05:21.604 ********* 
ok: [lobsters.xen.prgmr.com] => (item={u'dest': u'/etc', u'file': u'logrotate.conf'})
ok: [lobsters.xen.prgmr.com] => (item={u'dest': u'/etc', u'file': u'tarsnap.conf'})

TASK [tarsnap : copy up logrotate.d] ***************************************************************************************************************************************************************
Wednesday 09 May 2018  09:33:32 -0500 (0:00:09.195)       0:05:30.799 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : remove logrotate package's cron job] ***********************************************************************************************************************************************
Wednesday 09 May 2018  09:34:09 -0500 (0:00:37.246)       0:06:08.045 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : copy up backup script] *************************************************************************************************************************************************************
Wednesday 09 May 2018  09:34:11 -0500 (0:00:01.363)       0:06:09.409 ********* 
ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : add crontab entry] *****************************************************************************************************************************************************************
Wednesday 09 May 2018  09:34:16 -0500 (0:00:05.095)       0:06:14.504 ********* 
ok: [lobsters.xen.prgmr.com]

PLAY RECAP *****************************************************************************************************************************************************************************************
lobsters.xen.prgmr.com     : ok=68   changed=2    unreachable=0    failed=0   

Wednesday 09 May 2018  09:34:17 -0500 (0:00:01.485)       0:06:15.990 ********* 
=============================================================================== 
lobsters : copy templates and icons -------------------------------------------------------------------------------------------------------------------------------------------------------- 45.28s
tarsnap : copy up logrotate.d -------------------------------------------------------------------------------------------------------------------------------------------------------------- 37.25s
mariadb : mariadb config files ------------------------------------------------------------------------------------------------------------------------------------------------------------- 37.13s
sysadm : cp dot,a ~a ----------------------------------------------------------------------------------------------------------------------------------------------------------------------- 34.95s
lobsters : install bundler ----------------------------------------------------------------------------------------------------------------------------------------------------------------- 14.87s
nginx : apt-get install nginx -------------------------------------------------------------------------------------------------------------------------------------------------------------- 11.70s
postfix : cp /etc/postfix ------------------------------------------------------------------------------------------------------------------------------------------------------------------ 11.55s
tarsnap : copy up logrotate and tarsnap configs --------------------------------------------------------------------------------------------------------------------------------------------- 9.20s
Gathering Facts ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------- 7.17s
postfix : cp /etc/default/opendkim ---------------------------------------------------------------------------------------------------------------------------------------------------------- 6.66s
postfix : apt-get install postfix ----------------------------------------------------------------------------------------------------------------------------------------------------------- 6.61s
Gathering Facts ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------- 6.16s
mariadb : apt-get install mariadb ----------------------------------------------------------------------------------------------------------------------------------------------------------- 5.82s
lobsters : apt-get install lobsters dependencies -------------------------------------------------------------------------------------------------------------------------------------------- 5.59s
unicorn : apt-get install unicorn ----------------------------------------------------------------------------------------------------------------------------------------------------------- 5.54s
tarsnap : apt-get install tarsnap ----------------------------------------------------------------------------------------------------------------------------------------------------------- 5.43s
Gathering Facts ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------- 5.39s
unicorn : copy up unicorn config ------------------------------------------------------------------------------------------------------------------------------------------------------------ 5.38s
Gathering Facts ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------- 5.31s
Gathering Facts ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------- 5.29s

real    6m20.001s                                                                                                                                                                                   
user    0m41.536s                                                                                                                                                                                   
sys     0m10.447s

[jstoja]

The recommended way of structuring playbooks helps a lot with this (by splitting the setup and the actual deployment of the app).

Most of the time, you won’t update anything but the rails app. The easiest way for you to do this faster is to simply use the « -t lobsters » option to specify you want only the tags matching lobsters. That should run only the lobsters role that should take less than a minute.

When I can, I’ll try to deep a bit more with this, but in general, Ansible is not the fastest deployment tool unless structured to be so.

Julien

On 9 May 2018, at 16:43, Peter Bhat Harkins notifications@github.com wrote:

With the ssh config I added we've slightly reduced runtime to 6m20.001s.

Here's a run with profiling enabled. It looks like the biggest timesinks are running apt-get, copying files, and repeatedly gathering facts. Let me reiterate that this is a run with no changes, no packages are added or removed, no files have been added or edited, etc.

PLAY [mariadb] *****

TASK [Gathering Facts] ***** Wednesday 09 May 2018 09:28:01 -0500 (0:00:00.029) 0:00:00.029 * ok: [lobsters.xen.prgmr.com]

TASK [systype : set_fact arch, family, platform] *** Wednesday 09 May 2018 09:28:07 -0500 (0:00:06.158) 0:00:06.188 * ok: [lobsters.xen.prgmr.com]

TASK [mariadb : include_tasks] ***** Wednesday 09 May 2018 09:28:09 -0500 (0:00:01.097) 0:00:07.285 * included: /home/pushcx/code/l-ansible/roles/mariadb/tasks/apt.yml for lobsters.xen.prgmr.com

TASK [mariadb : apt-get install mariadb] *** Wednesday 09 May 2018 09:28:09 -0500 (0:00:00.036) 0:00:07.322 * ok: [lobsters.xen.prgmr.com] => (item=[u'mariadb-server'])

TASK [mariadb : include_tasks] ***** Wednesday 09 May 2018 09:28:14 -0500 (0:00:05.823) 0:00:13.146 * skipping: [lobsters.xen.prgmr.com]

TASK [mariadb : mariadb config files] ** Wednesday 09 May 2018 09:28:14 -0500 (0:00:00.024) 0:00:13.171 ***** ok: [lobsters.xen.prgmr.com]

TASK [mariadb : Enable mariadb at startup] ***** Wednesday 09 May 2018 09:28:52 -0500 (0:00:37.128) 0:00:50.299 * ok: [lobsters.xen.prgmr.com]

PLAY [unicorn] *****

TASK [Gathering Facts] ***** Wednesday 09 May 2018 09:28:54 -0500 (0:00:02.047) 0:00:52.346 * ok: [lobsters.xen.prgmr.com]

TASK [systype : set_fact arch, family, platform] *** Wednesday 09 May 2018 09:28:59 -0500 (0:00:05.386) 0:00:57.733 * ok: [lobsters.xen.prgmr.com]

TASK [unicorn : include_tasks] ***** Wednesday 09 May 2018 09:29:00 -0500 (0:00:01.266) 0:00:58.999 * included: /home/pushcx/code/l-ansible/roles/unicorn/tasks/apt.yml for lobsters.xen.prgmr.com

TASK [unicorn : apt-get install unicorn] *** Wednesday 09 May 2018 09:29:00 -0500 (0:00:00.034) 0:00:59.034 * ok: [lobsters.xen.prgmr.com] => (item=[u'unicorn'])

TASK [unicorn : include_tasks] ***** Wednesday 09 May 2018 09:29:06 -0500 (0:00:05.539) 0:01:04.573 * skipping: [lobsters.xen.prgmr.com]

TASK [unicorn : lobsters directory] **** Wednesday 09 May 2018 09:29:06 -0500 (0:00:00.023) 0:01:04.596 ***** ok: [lobsters.xen.prgmr.com] => (item=http) ok: [lobsters.xen.prgmr.com] => (item=run) ok: [lobsters.xen.prgmr.com] => (item=log)

TASK [unicorn : copy up unicorn config] **** Wednesday 09 May 2018 09:29:10 -0500 (0:00:04.324) 0:01:08.921 ***** ok: [lobsters.xen.prgmr.com]

TASK [unicorn : copy unicorn systemd service config] *** Wednesday 09 May 2018 09:29:16 -0500 (0:00:05.376) 0:01:14.298 * ok: [lobsters.xen.prgmr.com]

TASK [unicorn : just force systemd to reread configs] ** Wednesday 09 May 2018 09:29:20 -0500 (0:00:04.230) 0:01:18.529 ***** ok: [lobsters.xen.prgmr.com]

PLAY [lobsters] ****

TASK [Gathering Facts] ***** Wednesday 09 May 2018 09:29:24 -0500 (0:00:03.942) 0:01:22.471 * ok: [lobsters.xen.prgmr.com]

TASK [systype : set_fact arch, family, platform] *** Wednesday 09 May 2018 09:29:31 -0500 (0:00:07.166) 0:01:29.637 * ok: [lobsters.xen.prgmr.com]

TASK [lobsters : include_tasks] **** Wednesday 09 May 2018 09:29:32 -0500 (0:00:01.313) 0:01:30.951 ***** included: /home/pushcx/code/l-ansible/roles/lobsters/tasks/apt.yml for lobsters.xen.prgmr.com

TASK [lobsters : apt-get install lobsters dependencies] **** Wednesday 09 May 2018 09:29:32 -0500 (0:00:00.035) 0:01:30.987 ***** ok: [lobsters.xen.prgmr.com] => (item=[u'cmake', u'g++', u'gcc', u'git', u'libc-dev', u'libmysqlclient-dev', u'libsqlite3-dev', u'make', u'mariadb-client', u'nodejs', u'ruby2.3', u'ruby2.3-dev', u'sqlite3'])

TASK [lobsters : include_tasks] **** Wednesday 09 May 2018 09:29:38 -0500 (0:00:05.588) 0:01:36.575 ***** skipping: [lobsters.xen.prgmr.com]

TASK [lobsters : groupadd lobsters] **** Wednesday 09 May 2018 09:29:38 -0500 (0:00:00.023) 0:01:36.599 ***** ok: [lobsters.xen.prgmr.com]

TASK [lobsters : useradd lobsters] ***** Wednesday 09 May 2018 09:29:39 -0500 (0:00:00.734) 0:01:37.334 * ok: [lobsters.xen.prgmr.com]

TASK [lobsters : mkdir ~lobste.rs/.%] ** Wednesday 09 May 2018 09:29:41 -0500 (0:00:02.155) 0:01:39.489 ***** ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'02700', u'file': u'ssh'})

TASK [lobsters : cp % ~lobsters/.%] **** Wednesday 09 May 2018 09:29:43 -0500 (0:00:01.867) 0:01:41.357 ***** ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0600', u'file': u'ssh/known_hosts'})

TASK [lobsters : git clone lobsters] *** Wednesday 09 May 2018 09:29:47 -0500 (0:00:03.982) 0:01:45.340 * ok: [lobsters.xen.prgmr.com]

TASK [lobsters : check if bundler needs installing] **** Wednesday 09 May 2018 09:29:49 -0500 (0:00:02.433) 0:01:47.774 ***** changed: [lobsters.xen.prgmr.com]

TASK [lobsters : install bundler] ** Wednesday 09 May 2018 09:29:51 -0500 (0:00:01.786) 0:01:49.560 ***** changed: [lobsters.xen.prgmr.com]

TASK [lobsters : bundle install] *** Wednesday 09 May 2018 09:30:06 -0500 (0:00:14.867) 0:02:04.428 * ok: [lobsters.xen.prgmr.com]

TASK [lobsters : migrate database] ***** Wednesday 09 May 2018 09:30:08 -0500 (0:00:02.791) 0:02:07.219 * skipping: [lobsters.xen.prgmr.com]

TASK [lobsters : copy templates and icons] ***** Wednesday 09 May 2018 09:30:09 -0500 (0:00:00.020) 0:02:07.240 * ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0600', u'file': u'app'}) ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0644', u'file': u'public'})

TASK [lobsters : recompile assets] ***** Wednesday 09 May 2018 09:30:54 -0500 (0:00:45.275) 0:02:52.515 * skipping: [lobsters.xen.prgmr.com]

TASK [lobsters : restart unicorn] ** Wednesday 09 May 2018 09:30:54 -0500 (0:00:00.020) 0:02:52.535 ***** skipping: [lobsters.xen.prgmr.com]

TASK [lobsters : cp cron script] *** Wednesday 09 May 2018 09:30:54 -0500 (0:00:00.019) 0:02:52.555 * ok: [lobsters.xen.prgmr.com]

TASK [lobsters : add crontab entry] **** Wednesday 09 May 2018 09:30:58 -0500 (0:00:04.139) 0:02:56.695 ***** ok: [lobsters.xen.prgmr.com]

PLAY [nginx] ***

TASK [Gathering Facts] ***** Wednesday 09 May 2018 09:31:00 -0500 (0:00:01.877) 0:02:58.572 * ok: [lobsters.xen.prgmr.com]

TASK [systype : set_fact arch, family, platform] *** Wednesday 09 May 2018 09:31:05 -0500 (0:00:05.293) 0:03:03.866 * ok: [lobsters.xen.prgmr.com]

TASK [nginx : include_tasks] *** Wednesday 09 May 2018 09:31:06 -0500 (0:00:01.293) 0:03:05.160 * included: /home/pushcx/code/l-ansible/roles/nginx/tasks/apt.yml for lobsters.xen.prgmr.com

TASK [nginx : apt-get install nginx] *** Wednesday 09 May 2018 09:31:06 -0500 (0:00:00.047) 0:03:05.207 * ok: [lobsters.xen.prgmr.com] => (item=[u'nginx'])

TASK [nginx : include_tasks] *** Wednesday 09 May 2018 09:31:18 -0500 (0:00:11.700) 0:03:16.907 * skipping: [lobsters.xen.prgmr.com]

PLAY [postfix] *****

TASK [Gathering Facts] ***** Wednesday 09 May 2018 09:31:18 -0500 (0:00:00.029) 0:03:16.937 * ok: [lobsters.xen.prgmr.com]

TASK [systype : set_fact arch, family, platform] *** Wednesday 09 May 2018 09:31:23 -0500 (0:00:04.509) 0:03:21.447 * ok: [lobsters.xen.prgmr.com]

TASK [postfix : include_tasks] ***** Wednesday 09 May 2018 09:31:24 -0500 (0:00:01.321) 0:03:22.768 * included: /home/pushcx/code/l-ansible/roles/postfix/tasks/apt.yml for lobsters.xen.prgmr.com

TASK [postfix : apt-get install postfix] *** Wednesday 09 May 2018 09:31:24 -0500 (0:00:00.033) 0:03:22.802 * ok: [lobsters.xen.prgmr.com] => (item=[u'opendkim', u'postfix'])

TASK [postfix : include_tasks] ***** Wednesday 09 May 2018 09:31:31 -0500 (0:00:06.605) 0:03:29.407 * skipping: [lobsters.xen.prgmr.com]

TASK [postfix : cp /etc/default/opendkim] ** Wednesday 09 May 2018 09:31:31 -0500 (0:00:00.023) 0:03:29.430 ***** ok: [lobsters.xen.prgmr.com] => (item={u'name': u'etc/default/opendkim', u'mode': u'0644'}) ok: [lobsters.xen.prgmr.com] => (item={u'name': u'etc/opendkim.conf', u'mode': u'0644'})

TASK [postfix : cp /etc/aliases] *** Wednesday 09 May 2018 09:31:37 -0500 (0:00:06.660) 0:03:36.091 * ok: [lobsters.xen.prgmr.com]

TASK [postfix : cp /etc/postfix] *** Wednesday 09 May 2018 09:31:41 -0500 (0:00:03.743) 0:03:39.834 * ok: [lobsters.xen.prgmr.com] => (item={u'name': u'main.cf', u'mode': u'0644'}) ok: [lobsters.xen.prgmr.com] => (item={u'name': u'master.cf', u'mode': u'0644'}) ok: [lobsters.xen.prgmr.com] => (item={u'name': u'transport', u'mode': u'0644'})

TASK [postfix : postmap] *** Wednesday 09 May 2018 09:31:53 -0500 (0:00:11.553) 0:03:51.387 * skipping: [lobsters.xen.prgmr.com]

TASK [postfix : postfix reload] **** Wednesday 09 May 2018 09:31:53 -0500 (0:00:00.020) 0:03:51.408 ***** skipping: [lobsters.xen.prgmr.com]

PLAY [sysadm] **

TASK [Gathering Facts] ***** Wednesday 09 May 2018 09:31:53 -0500 (0:00:00.026) 0:03:51.434 * ok: [lobsters.xen.prgmr.com]

TASK [systype : set_fact arch, family, platform] *** Wednesday 09 May 2018 09:31:58 -0500 (0:00:04.967) 0:03:56.401 * ok: [lobsters.xen.prgmr.com]

TASK [sysadm : include_tasks] ** Wednesday 09 May 2018 09:31:59 -0500 (0:00:01.535) 0:03:57.937 ***** included: /home/pushcx/code/l-ansible/roles/sysadm/tasks/apt.yml for lobsters.xen.prgmr.com

TASK [sysadm : apt-get install sysadm dependencies] **** Wednesday 09 May 2018 09:31:59 -0500 (0:00:00.035) 0:03:57.973 ***** ok: [lobsters.xen.prgmr.com] => (item=[u'fail2ban', u'ksh', u'locate', u'nvi', u'tmux'])

TASK [sysadm : include_tasks] ** Wednesday 09 May 2018 09:32:04 -0500 (0:00:05.021) 0:04:02.994 ***** skipping: [lobsters.xen.prgmr.com]

TASK [sysadm : include sudo supplementary group] *** Wednesday 09 May 2018 09:32:04 -0500 (0:00:00.029) 0:04:03.023 * ok: [lobsters.xen.prgmr.com]

TASK [sysadm : include_tasks] ** Wednesday 09 May 2018 09:32:04 -0500 (0:00:00.055) 0:04:03.079 ***** included: /home/pushcx/code/l-ansible/roles/sysadm/tasks/a.yml for lobsters.xen.prgmr.com

TASK [sysadm : groupadd a] ***** Wednesday 09 May 2018 09:32:04 -0500 (0:00:00.036) 0:04:03.116 * ok: [lobsters.xen.prgmr.com]

TASK [sysadm : useradd a] ** Wednesday 09 May 2018 09:32:05 -0500 (0:00:00.676) 0:04:03.793 ***** ok: [lobsters.xen.prgmr.com]

TASK [sysadm : add a's ssh keys] *** Wednesday 09 May 2018 09:32:07 -0500 (0:00:01.878) 0:04:05.671 * ok: [lobsters.xen.prgmr.com] => (item={u'file': u'a-20171001.pub'})

TASK [sysadm : cp dot,a ~a] **** Wednesday 09 May 2018 09:32:10 -0500 (0:00:02.680) 0:04:08.352 ***** ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'bashrc'}) ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'dcrc'}) ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'exrc'}) ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'inputrc'}) ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'kshrc'}) ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'nexrc'}) ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'profile'}) ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'tmux.conf'}) ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'vimrc'})

TASK [sysadm : rm dot,a ~a/] *** Wednesday 09 May 2018 09:32:45 -0500 (0:00:34.954) 0:04:43.307 * ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'bash_logout'}) ok: [lobsters.xen.prgmr.com] => (item={u'mode': u'0640', u'file': u'bash_profile'})

TASK [sysadm : include_tasks] ** Wednesday 09 May 2018 09:32:48 -0500 (0:00:03.653) 0:04:46.960 ***** included: /home/pushcx/code/l-ansible/roles/sysadm/tasks/pushcx.yml for lobsters.xen.prgmr.com

TASK [sysadm : groupadd pushcx] **** Wednesday 09 May 2018 09:32:48 -0500 (0:00:00.030) 0:04:46.990 ***** ok: [lobsters.xen.prgmr.com]

TASK [sysadm : useradd pushcx] ***** Wednesday 09 May 2018 09:32:50 -0500 (0:00:01.889) 0:04:48.879 * ok: [lobsters.xen.prgmr.com]

TASK [sysadm : add pushcx's ssh keys] ** Wednesday 09 May 2018 09:32:52 -0500 (0:00:02.210) 0:04:51.090 ***** ok: [lobsters.xen.prgmr.com] => (item={u'file': u'pushcx-20171001.pub'})

PLAY [tarsnap] *****

TASK [Gathering Facts] ***** Wednesday 09 May 2018 09:32:56 -0500 (0:00:03.153) 0:04:54.244 * ok: [lobsters.xen.prgmr.com]

TASK [systype : set_fact arch, family, platform] *** Wednesday 09 May 2018 09:33:01 -0500 (0:00:05.313) 0:04:59.557 * ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : include_tasks] ***** Wednesday 09 May 2018 09:33:02 -0500 (0:00:00.957) 0:05:00.515 * included: /home/pushcx/code/l-ansible/roles/tarsnap/tasks/apt.yml for lobsters.xen.prgmr.com

TASK [tarsnap : copy up tarsnap key] *** Wednesday 09 May 2018 09:33:02 -0500 (0:00:00.046) 0:05:00.561 * ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : add tarsnap key] *** Wednesday 09 May 2018 09:33:07 -0500 (0:00:05.149) 0:05:05.710 * ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : add tarsnap repo] ** Wednesday 09 May 2018 09:33:10 -0500 (0:00:03.495) 0:05:09.206 ***** ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : apt-get install tarsnap] *** Wednesday 09 May 2018 09:33:13 -0500 (0:00:02.061) 0:05:11.268 * ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : apt-get install logrotate] ***** Wednesday 09 May 2018 09:33:18 -0500 (0:00:05.425) 0:05:16.693 * ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : copy up logrotate and tarsnap configs] ***** Wednesday 09 May 2018 09:33:23 -0500 (0:00:04.910) 0:05:21.604 * ok: [lobsters.xen.prgmr.com] => (item={u'dest': u'/etc', u'file': u'logrotate.conf'}) ok: [lobsters.xen.prgmr.com] => (item={u'dest': u'/etc', u'file': u'tarsnap.conf'})

TASK [tarsnap : copy up logrotate.d] *** Wednesday 09 May 2018 09:33:32 -0500 (0:00:09.195) 0:05:30.799 * ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : remove logrotate package's cron job] *** Wednesday 09 May 2018 09:34:09 -0500 (0:00:37.246) 0:06:08.045 * ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : copy up backup script] ***** Wednesday 09 May 2018 09:34:11 -0500 (0:00:01.363) 0:06:09.409 * ok: [lobsters.xen.prgmr.com]

TASK [tarsnap : add crontab entry] ***** Wednesday 09 May 2018 09:34:16 -0500 (0:00:05.095) 0:06:14.504 * ok: [lobsters.xen.prgmr.com]

PLAY RECAP ***** lobsters.xen.prgmr.com : ok=68 changed=2 unreachable=0 failed=0

Wednesday 09 May 2018 09:34:17 -0500 (0:00:01.485) 0:06:15.990 ***** =============================================================================== lobsters : copy templates and icons -------------------------------------------------------------------------------------------------------------------------------------------------------- 45.28s tarsnap : copy up logrotate.d -------------------------------------------------------------------------------------------------------------------------------------------------------------- 37.25s mariadb : mariadb config files ------------------------------------------------------------------------------------------------------------------------------------------------------------- 37.13s sysadm : cp dot,a ~a ----------------------------------------------------------------------------------------------------------------------------------------------------------------------- 34.95s lobsters : install bundler ----------------------------------------------------------------------------------------------------------------------------------------------------------------- 14.87s nginx : apt-get install nginx -------------------------------------------------------------------------------------------------------------------------------------------------------------- 11.70s postfix : cp /etc/postfix ------------------------------------------------------------------------------------------------------------------------------------------------------------------ 11.55s tarsnap : copy up logrotate and tarsnap configs --------------------------------------------------------------------------------------------------------------------------------------------- 9.20s Gathering Facts ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------- 7.17s postfix : cp /etc/default/opendkim ---------------------------------------------------------------------------------------------------------------------------------------------------------- 6.66s postfix : apt-get install postfix ----------------------------------------------------------------------------------------------------------------------------------------------------------- 6.61s Gathering Facts ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------- 6.16s mariadb : apt-get install mariadb ----------------------------------------------------------------------------------------------------------------------------------------------------------- 5.82s lobsters : apt-get install lobsters dependencies -------------------------------------------------------------------------------------------------------------------------------------------- 5.59s unicorn : apt-get install unicorn ----------------------------------------------------------------------------------------------------------------------------------------------------------- 5.54s tarsnap : apt-get install tarsnap ----------------------------------------------------------------------------------------------------------------------------------------------------------- 5.43s Gathering Facts ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------- 5.39s unicorn : copy up unicorn config ------------------------------------------------------------------------------------------------------------------------------------------------------------ 5.38s Gathering Facts ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------- 5.31s Gathering Facts ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------- 5.29s

real 6m20.001s
user 0m41.536s
sys 0m10.447s — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub, or mute the thread.

[pushcx]

As I noted in the first comment, we've had bugs caused by running just the lobsters tag and I'd like to get away from that. For example: the my.cnf that was recently templated didn't go out for a couple weeks because I thought it was a copy from prod. When it did go live, the first symptom was that backups broke because mysqldump read an incorrect value for the mysql socket. And the playbook didn't restart mariadb, so there was the added wrinkle that the running server and config file were out of sync. I've fixed these issues this morning, but all of this was made harder by the delays introduced by only running the parts of the playbook related to the rails app. I see not running the entire playbook as a significant source of instability and opened this issue because I want to fix the performance problems that have us taking this risk.

[PhilArmstrong]

The copy module says it might be better to use synchronize when shifting lots of files - From the docs it appears it might be copying & fsyncing each file individually in "copy templates and icons" ? I bet you could mark some of these tasks async as well, as they can run independently of other package installs. Using rsync (i.e. synchronise) on already extant files should be /much/ quicker.

[pushcx]

Across all our roles, we have 75 files, not the hundreds that copy's docs warn against. The specific copy task at the top of the list taking 45s is 9 files in 60K. That kind of huge delay makes me think there's some kind of fundamental misconfiguration of ansible that it's tearing down and recreating the ssh tunnel for every file or something.

I've looked at async, but from blog posts it sounded like even if the playbook registers variables that others use (eg. don't restart mariadb unless its config files changed), we have to manually track the dependencies between tasks. This seems really brittle, especially for things like unicorn's dependency on mariadb that crosses tags/roles.

[jstoja]

From my experience:

• async is pretty tricky and there is many cases where it doesn't work well
• for most of you roles you don't need (yet) gathering facts so you could probably add gather_facts: no where you don't want it.
• rsync is way faster, but has some quirks and limitations.
• apt looks pretty slow too, maybe the mirrors could be changed to match closer ones. You could also use cache_valid_time: 3600 to skip the apt-get update for each package installation.
• systype seems to add 5sec for each role too. The #20 will solve this.

I hope this will help you to have something faster.

[pushcx]

time now says the full playbook takes 3m40.402s, which is noticeably less bad.

[nogweii]

there's some kind of fundamental misconfiguration of ansible that it's tearing down and recreating the ssh tunnel for every file or something

I think something like that is indeed happening. Mitogen might be something to look into.

[jstoja]

Ansible is already reusing the ssh connection since @pushcx added the ControlPersist option. Mitogen is something that is useful when you have many servers to provision, here there is just one, so I doubt it would improve anything.

Cf https://docs.ansible.com/ansible/latest/reference_appendices/faq.html#how-do-i-get-ansible-to-reuse-connections-enable-kerberized-ssh-or-have-ansible-pay-attention-to-my-local-ssh-config-file

On 29 Sep 2018, at 19:04, No GUI notifications@github.com wrote:

there's some kind of fundamental misconfiguration of ansible that it's tearing down and recreating the ssh tunnel for every file or something

I think something like that is indeed happening. Mitogen might be something to look into.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or mute the thread.

[pushcx]

Wow. This bullet point from Mitogen's docs sounds like an accurate description of our slow playbook and a likely cause:

Processes are aggressively reused, avoiding the cost of invoking Python and recompiling imports, saving 300-800 ms for every playbook step. [...] The effect is most potent on playbooks that execute many short-lived actions, where Ansible’s overhead dominates the cost of the operation, for example when executing large with_items loops to run simple commands or write files.

@evaryont: Thanks for sharing this. I'm going to set aside time to read these docs and experiment, hopefully in the next week or two.

[jstoja]

Indeed! I wasn’t aware of these points! Sorry for the dismiss of the idea, I hope this will help!

I’ll have a look too if I manage to take time!

On 29 Sep 2018, at 20:54, Peter Bhat Harkins notifications@github.com wrote:

Wow. This bullet point from Mitogen's docs sounds like an accurate description of our slow playbook and a likely cause:

Processes are aggressively reused, avoiding the cost of invoking Python and recompiling imports, saving 300-800 ms for every playbook step. [...] The effect is most potent on playbooks that execute many short-lived actions, where Ansible’s overhead dominates the cost of the operation, for example when executing large with_items loops to run simple commands or write files.

@evaryont: Thanks for sharing this. I'm going to set aside time to read these docs and experiment, hopefully in the next week or two.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or mute the thread.

[pushcx]

Getting pipelining working with ControlPersist took this down to 90s. It's less objectionable, though still high for my intuition.