changed 6 years ago  
Linked with GitHub
tags: cloud-init bootspeed

Azure async mkfs/mount testing

Modifying cloud-init to utilize systemd-makefs for mkfs + mount service in parallel to cloud-init execution. Azure datasouce includes built-in config for partitioning, formating and mounting the ephemeral disk. This work is done serialy and runs before cloud-init generates ssh keys which delays the time to ssh login.

An initial test on an L4s with 700GB ephemeral and attaching a 1023GB secondary disk configured to be formatted with ext4 and mounted result in a time to sshd being ready of about 44 seconds. The following cloud-config attached to the instance is used to trigger a particular path through cloud-init.

#cloud-config
disk_setup:
  ephemeral0:
    table_type: gpt
    layout: [100]
    overwrite: true
fs_setup:
  - filesystem: ext4
    device: ephemeral0.1
  - filesystem: ext4
    device: /dev/sdc
mounts:
  - ['ephemeral0.1', '/mnt', 'ext4', 'defaults,nofail,x-systemd.requires=cloud-init.service,comment=cloudconfig']
  - ['/dev/sdc', '/opt/data', 'ext4', 'defaults,nofail,x-systemd.requires=cloud-init.service,comment=cloudconfig']

Collecting times from systemd and cloud-init, note we spend 16.6 seconds in 'disk_setup' (partitioning and mkfs), and that sshd is started at 42 seconds into the boot.

​​rharper@lazy-gator:~$ systemd-analyze 
Startup finished in 6.768s (kernel) + 39.825s (userspace) = 46.593s
graphical.target reached after 39.223s in userspace
rharper@lazy-gator:~$ systemd-analyze blame | head 
​​       23.680s cloud-init.service
​​        4.178s cloud-init-local.service
​​        2.632s lxd-containers.service
​​        2.563s snapd.seeded.service
​​        2.488s pollinate.service
​​        2.147s snapd.service
​​        1.651s dev-sda1.device
​​        1.643s keyboard-setup.service
​​        1.604s cloud-config.service
​​        1.395s systemd-networkd-wait-online.service
rharper@lazy-gator:~$ cloud-init analyze blame | head 
-- Boot Record 01 --
​​   16.65300s (init-network/config-disk_setup)
​​   03.19600s (azure-ds/_report_ready)
​​   01.13700s (init-network/config-resizefs)
​​   00.73300s (modules-config/config-grub-dpkg)
​​   00.51700s (init-network/config-growpart)
​​   00.29400s (modules-config/config-apt-configure)
​​   00.26100s (init-network/config-users-groups)
​​   00.25600s (azure-ds/generate_certificate)
​​   00.20000s (init-network/config-mounts)
rharper@lazy-gator:~$ journalctl -b -o short-monotonic -u ssh.service 
-- Logs begin at Wed 2019-06-26 18:26:26 UTC, end at Wed 2019-06-26 18:28:05 UTC. --
[   41.942988] lazy-gator systemd[1]: Starting OpenBSD Secure Shell server...
[   42.029963] lazy-gator sshd[1628]: Server listening on 0.0.0.0 port 22.
[   42.030204] lazy-gator sshd[1628]: Server listening on :: port 22.
[   42.032974] lazy-gator systemd[1]: Started OpenBSD Secure Shell server.
[  106.705732] lazy-gator sshd[1964]: Accepted publickey for rharper from 24.27.56.250 port 41570 ssh2: RSA SHA256:i/gcstwtMO9wYD0wsVC5WWw9vhLffyjWiLTpzKGRjSk
[  106.707049] lazy-gator sshd[1964]: pam_unix(sshd:session): session opened for user rharper by (uid=0)

Using x-systemd.makefs to defer the mkfs and mount (to run in parallel with cloud-init), we spend just 2.7 seconds in 'disk_setup' (partitioning is not handled by systemd-makefs), and deferred the ~17 seconds of mkfs to systemd units. The net result is sshd is started after 14 seconds of uptime.

rharper@gator-bait:~$ systemd-analyze
Startup finished in 5.671s (kernel) + 20.027s (userspace) = 25.698s
graphical.target reached after 19.404s in userspace
rharper@gator-bait:~$ systemd-analyze blame | head 
         10.610s systemd-mkfs@dev-sdc.service
          6.789s systemd-mkfs@dev-disk-cloud-azure_resource\x2dpart1.service
          4.188s cloud-init.service
          1.602s systemd-networkd-wait-online.service
          1.337s cloud-init-local.service
           862ms cloud-config.service
           655ms dev-sda1.device
           622ms cloud-final.service
           558ms keyboard-setup.service
           414ms snapd.service
rharper@gator-bait:~$ cloud-init analyze blame | head 
-- Boot Record 01 --
     02.74900s (init-network/config-disk_setup/partition-dev-disk-cloud-azure_resource)
     00.36800s (azure-ds/list_possible_azure_ds_devs)
     00.28300s (init-network/config-ssh)
     00.23200s (modules-config/config-grub-dpkg)
     00.13900s (init-network/config-mounts)
     00.11100s (init-network/config-growpart)
     00.10700s (azure-ds/_get_metadata_from_imds)
     00.08600s (modules-config/config-apt-configure)
     00.06600s (modules-final/config-keys-to-console)
rharper@gator-bait:~$ journalctl -b -o short-monotonic -u ssh.service 
-- Logs begin at Wed 2019-06-26 17:21:38 UTC, end at Wed 2019-06-26 18:28:09 UTC. --
[   14.101460] gator-bait systemd[1]: Starting OpenBSD Secure Shell server...
[   14.143674] gator-bait sshd[1240]: Server listening on 0.0.0.0 port 22.
[   14.147382] gator-bait sshd[1240]: Server listening on :: port 22.
[   14.147446] gator-bait systemd[1]: Started OpenBSD Secure Shell server.
[   19.821691] gator-bait sshd[1389]: Accepted publickey for rharper from 24.27.56.250 port 53032 ssh2: RSA SHA256:i/gcstwtMO9wYD0wsVC5WWw9vhLffyjWiLTpzKGRjSk
[   19.822935] gator-bait sshd[1389]: pam_unix(sshd:session): session opened for user rharper by (uid=0)
[   24.110138] gator-bait sshd[1389]: pam_unix(sshd:session): session closed for user rharper
[   24.349121] gator-bait sshd[1591]: Accepted publickey for rharper from 24.27.56.250 port 53034 ssh2: RSA SHA256:i/gcstwtMO9wYD0wsVC5WWw9vhLffyjWiLTpzKGRjSk
[   24.350186] gator-bait sshd[1591]: pam_unix(sshd:session): session opened for user rharper by (uid=0)
[  761.839199] gator-bait sshd[2540]: Accepted publickey for rharper from 24.27.56.250 port 53130 ssh2: RSA SHA256:i/gcstwtMO9wYD0wsVC5WWw9vhLffyjWiLTpzKGRjSk
[  761.855243] gator-bait sshd[2540]: pam_unix(sshd:session): session opened for user rharper by (uid=0)
Select a repo