title: EC2 userdata script runs very slowly on Centos7 AMI
body: <p>There appears to be a 25 second delay every time a userdata script touches the disk on the centos 7 AMI from AWS marketplace.</p>
  
  <p>Here's my script:</p>
  
  <pre><code>#!/bin/bash -ex
  echo "[TIMER] START $(date +%s.%N)"
  current_user=$(whoami)
  echo "Running as: $current_user"
  sudo id -u myuser &amp;&gt;/dev/null || sudo useradd myuser
  echo "[TIMER] CreatedUser $(date +%s.%N)"
  time sudo yum update -y
  echo "[TIMER] Yum Update $(date +%s.%N)"
  sudo mkdir -p /opt/myuser/resources
  echo "[TIMER] Create /opt/myuser/resources $(date +%s.%N)"
  
  sudo bash -c "cat &gt; /etc/systemd/system/my-service.service" &lt;&lt;EOF
  [Unit]
  Description=My Service
  After=network-online.target
  
  [Service]
  User=myuser
  Group=myuser
  Type=oneshot
  RemainAfterExit=yes
  ExecStart=/bin/bash -ex -c 'echo "Hello World"'
  
  [Install]
  Alias=my-service
  WantedBy=default.target
  EOF
  
  echo "[TIMER] Make my-service.service $(date +%s.%N)"
  sudo chmod 644 /etc/systemd/system/my-service.service
  echo "[TIMER] Chmod $(date +%s.%N)"
  sudo systemctl daemon-reload
  echo "[TIMER] daemon-reload $(date +%s.%N)"
  sudo systemctl enable my-service
  echo "[TIMER] enable $(date +%s.%N)"
  sudo systemctl start my-service
  echo "[TIMER] END: my-service $(date +%s.%N)"
  </code></pre>
  
  <p>I launch a c5.large of this AMI and use the above as my userdata script: <a href="https://aws.amazon.com/marketplace/pp/B00O7WM7QW" rel="nofollow noreferrer">https://aws.amazon.com/marketplace/pp/B00O7WM7QW</a> </p>
  
  <p>Timers result:</p>
  
  <pre><code>[TIMER] START 1546978269.809559549
  [TIMER] CreatedUser 1546978320.472706964
  [TIMER] Yum Update 1546978356.991642552
  [TIMER] Create /opt/myuser/resources 1546978382.033044767
  [TIMER] Make my-service.service 1546978407.074353857
  [TIMER] Chmod 1546978432.111791937
  [TIMER] daemon-reload 1546978457.195078083
  [TIMER] enable 1546978482.265036318
  [TIMER] END: my-service 1546978507.313735938
  </code></pre>
  
  <pre>
  | CENTOS 7                                                  |                      |             |
  |-----------------------------------------------------------|----------------------|-------------|
  |                                                           |                      |             |
  | log                                                       | timestamp            | seconds     |
  | [TIMER] START 1546978269.809559549                        | 1546978269.809559549 |             |
  | [TIMER] CreatedUser 1546978320.472706964                  | 1546978320.472706964 | 50.66315007 |
  | [TIMER] Yum Update 1546978356.991642552                   | 1546978356.991642552 | 36.51893997 |
  | [TIMER] Create /opt/myuser/resources 1546978382.033044767 | 1546978382.033044767 | 25.04139996 |
  | [TIMER] Make my-service.service 1546978407.074353857      | 1546978407.074353857 | 25.04131007 |
  | [TIMER] Chmod 1546978432.111791937                        | 1546978432.111791937 | 25.03743982 |
  | [TIMER] daemon-reload 1546978457.195078083                | 1546978457.195078083 | 25.08328009 |
  | [TIMER] enable 1546978482.265036318                       | 1546978482.265036318 | 25.06995988 |
  | [TIMER] END: my-service 1546978507.313735938              | 1546978507.313735938 | 25.04870009 |
  |                                                           |                      |             |
  |                                                           | total (s)            | 237.50418   |
  |                                                           |                      |             |
  |                                                           | total (m)            | 3.958402999 |
  </pre>
  
  <p>If you scroll to the right in my ASCII table you can see that simple commands like <code>mkdir</code>, <code>chmod</code>, and <code>useradd</code> are taking 25 seconds. Why does this happen?</p>
  
  <p>EDIT: </p>
  
  <p>contents of <code>/etc/hosts</code></p>
  
  <pre><code>$ hostname
  ip-172-31-40-213.us-west-2.compute.internal
  $ cat /etc/hosts
  127.0.0.1   localhost localhost.localdomain localhost4 localhost4.localdomain4
  ::1         localhost localhost.localdomain localhost6 localhost6.localdomain6
  </code></pre>
  
  <p>example log from <code>/var/log/messages</code>, the systemd logs show that creating the sudo session takes the 25 seconds:</p>
  
  <pre><code>Jan  9 23:50:32 ip-172-31-35-166 cloud-init: + echo '[TIMER] Make my-service.service 1547077832.899069408'
  Jan  9 23:50:32 ip-172-31-35-166 cloud-init: [TIMER] Make my-service.service 1547077832.899069408
  Jan  9 23:50:32 ip-172-31-35-166 cloud-init: + sudo chmod 644 /etc/systemd/system/my-service.service
  Jan  9 23:50:32 ip-172-31-35-166 systemd: Removed slice User Slice of root.
  Jan  9 23:50:32 ip-172-31-35-166 systemd: Created slice User Slice of root.
  Jan  9 23:50:32 ip-172-31-35-166 systemd: Started Session c3 of user root.
  Jan  9 23:50:57 ip-172-31-35-166 cloud-init: ++ date +%s.%N
  Jan  9 23:50:57 ip-172-31-35-166 cloud-init: + echo '[TIMER] Chmod 1547077857.946078493'
  Jan  9 23:50:57 ip-172-31-35-166 cloud-init: [TIMER] Chmod 1547077857.946078493
  </code></pre>
  
  <p><code>journalctl</code> log shows the likely culprit:</p>
  
  <pre><code>Jan 09 23:50:32 ip-172-31-35-166.us-west-2.compute.internal cloud-init[1197]: + echo '[TIMER] Make my-service.service 1547077832.899069408'
  Jan 09 23:50:32 ip-172-31-35-166.us-west-2.compute.internal cloud-init[1197]: [TIMER] Make my-service.service 1547077832.899069408
  Jan 09 23:50:32 ip-172-31-35-166.us-west-2.compute.internal cloud-init[1197]: + sudo chmod 644 /etc/systemd/system/my-service.service
  Jan 09 23:50:32 ip-172-31-35-166.us-west-2.compute.internal systemd[1]: Removed slice User Slice of root.
  Jan 09 23:50:32 ip-172-31-35-166.us-west-2.compute.internal sudo[13392]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 644 /etc/systemd/system/my-service.service
  Jan 09 23:50:32 ip-172-31-35-166.us-west-2.compute.internal systemd[1]: Created slice User Slice of root.
  Jan 09 23:50:32 ip-172-31-35-166.us-west-2.compute.internal systemd[1]: Started Session c3 of user root.
  Jan 09 23:50:57 ip-172-31-35-166.us-west-2.compute.internal sudo[13392]: pam_systemd(sudo:session): Failed to create session: Connection timed out
  Jan 09 23:50:57 ip-172-31-35-166.us-west-2.compute.internal sudo[13392]: pam_unix(sudo:session): session opened for user root by (uid=0)
  Jan 09 23:50:57 ip-172-31-35-166.us-west-2.compute.internal sudo[13392]: pam_unix(sudo:session): session closed for user root
  Jan 09 23:50:57 ip-172-31-35-166.us-west-2.compute.internal cloud-init[1197]: ++ date +%s.%N
  Jan 09 23:50:57 ip-172-31-35-166.us-west-2.compute.internal cloud-init[1197]: + echo '[TIMER] Chmod 1547077857.946078493'
  Jan 09 23:50:57 ip-172-31-35-166.us-west-2.compute.internal cloud-init[1197]: [TIMER] Chmod 1547077857.946078493
  </code></pre>
  
  <p>Googling more, I find: <a href="https://github.com/systemd/systemd/issues/2863" rel="nofollow noreferrer">https://github.com/systemd/systemd/issues/2863</a></p>
  
  <p>This has been fixed in a later version of systemd but centos on AWS EC2 comes with systemd version 219 and I can't really update it myself. Any suggestions? Is there some config I can place to avoid this issue? I can remove <em>most</em> instances of sudo in my userdata script but I do need it for things like:</p>
  
  <pre><code>sudo -H -u myuser bash -ex &lt;&lt;EOF
    ... commands
  EOF
  </code></pre>
  
  <p>FWIW Amazon Linux 2 comes with the same version of systemd but does not exhibit this behavior.</p>