← Back to team overview

yahoo-eng-team team mailing list archive

[Bug 1727358] Re: cloud-init is slow to complete init on minimized images

 

Could you run
  cloud-init collect-logs
And then attach the cloud-init.tar.gz

Also, Can you provide some information on what you were running?
 " cloud-init is slow to complete init on minimized images " 
How can I recreate this?

One curious thing there is:
 2017-10-25 13:22:07,157 - util.py[WARNING]: did not find either path /sys/class/dmi/id or dmidecode command

I suspect you have a kernel without CONFIG_DMI, which seems unfortunate or
possibly you're not on intel or arm64.

For large jumps in your log, it took ~ 9 seconds (13:22:07,337 ->
13:22:16,112) from the exit of cloud-init-local.service to get to
'cloud-init.service' printing its hello message.  That is basically the
time it took the network to come up.

Then we have a big jump (122 seconds):
 13:22:16,264 main.py[DEBUG]: no di_report found in config.
 13:24:38,088 stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>

Those two lines in a vm I have on a openstack look like this:
2017-10-11 15:08:26,685 - main.py[DEBUG]: no di_report found in config.
2017-10-11 15:08:27,031 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
2017-10-11 15:08:27,032 - stages.py[DEBUG]: Running module migrator (<module 'cloudinit.config.cc_migrator' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_migrator.py'>) with frequency always


That is ~ .5 seconds, which is not fast, but not 120 seconds either.


** Also affects: cloud-init
   Importance: Undecided
       Status: New

** Changed in: cloud-init (Ubuntu)
       Status: New => Incomplete

** Changed in: cloud-init
       Status: New => Incomplete

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to cloud-init.
https://bugs.launchpad.net/bugs/1727358

Title:
  cloud-init is slow to complete init on minimized images

Status in cloud-init:
  Incomplete
Status in cloud-init package in Ubuntu:
  Incomplete

Bug description:
  http://paste.ubuntu.com/25816789/ for the full logs.

  cloud-init is very slow to complete its initialization steps.
  Specifically, the 'init' takes over 150 seconds.

  Cloud-init v. 17.1 running 'init-local' at Wed, 25 Oct 2017 13:22:07 +0000. Up 2.39 seconds.
  2017-10-25 13:22:07,157 - util.py[WARNING]: did not find either path /sys/class/dmi/id or dmidecode command
  Cloud-init v. 17.1 running 'init' at Wed, 25 Oct 2017 13:22:16 +0000. Up 11.37 seconds.
  ci-info: ++++++++++++++++++++++++++++++++Net device info+++++++++++++++++++++++++++++++++
  ci-info: +--------+-------+-----------------+---------------+-------+-------------------+
  ci-info: | Device |   Up  |     Address     |      Mask     | Scope |     Hw-Address    |
  ci-info: +--------+-------+-----------------+---------------+-------+-------------------+
  ci-info: | ens3:  |  True | 192.168.100.161 | 255.255.255.0 |   .   | 52:54:00:bb:ad:fb |
  ci-info: | ens3:  |  True |        .        |       .       |   d   | 52:54:00:bb:ad:fb |
  ci-info: |  lo:   |  True |    127.0.0.1    |   255.0.0.0   |   .   |         .         |
  ci-info: |  lo:   |  True |        .        |       .       |   d   |         .         |
  ci-info: | sit0:  | False |        .        |       .       |   .   |         .         |
  ci-info: +--------+-------+-----------------+---------------+-------+-------------------+
  ci-info: ++++++++++++++++++++++++++++++++Route IPv4 info++++++++++++++++++++++++++++++++
  ci-info: +-------+---------------+---------------+-----------------+-----------+-------+
  ci-info: | Route |  Destination  |    Gateway    |     Genmask     | Interface | Flags |
  ci-info: +-------+---------------+---------------+-----------------+-----------+-------+
  ci-info: |   0   |    0.0.0.0    | 192.168.100.1 |     0.0.0.0     |    ens3   |   UG  |
  ci-info: |   1   | 192.168.100.0 |    0.0.0.0    |  255.255.255.0  |    ens3   |   U   |
  ci-info: |   2   | 192.168.100.1 |    0.0.0.0    | 255.255.255.255 |    ens3   |   UH  |
  ci-info: +-------+---------------+---------------+-----------------+-----------+-------+
  2017-10-25 13:24:38,187 - util.py[WARNING]: Failed to resize filesystem (cmd=('resize2fs', '/dev/root'))
  2017-10-25 13:24:38,193 - util.py[WARNING]: Running module resizefs (<module 'cloudinit.config.cc_resizefs' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_resizefs.py'>) failed
  Generating public/private rsa key pair.
  Your identification has been saved in /etc/ssh/ssh_host_rsa_key.
  Your public key has been saved in /etc/ssh/ssh_host_rsa_key.pub.
  The key fingerprint is:
  SHA256:LKNlCqqOgPB8KBKGfPhFO5Rs6fDMnAvVet/W9i4vLxY root@cloudimg
  The key's randomart image is:
  +---[RSA 2048]----+
  |                 |
  |    . +          |
  |   . O .         |
  |o . % +.         |
  |++.o %=.S        |
  |+=ooo=+o. . .E   |
  |* +.+.   . o o.  |
  |=. .      . .=.  |
  |+.          . B= |
  +----[SHA256]-----+
  Generating public/private dsa key pair.
  Your identification has been saved in /etc/ssh/ssh_host_dsa_key.
  Your public key has been saved in /etc/ssh/ssh_host_dsa_key.pub.
  The key fingerprint is:
  SHA256:dNWNyBHqTUCl820/vL0dEhOVDFYJzqr1WeuqV1PAmjk root@cloudimg
  The key's randomart image is:
  +---[DSA 1024]----+
  |         .oo=X==o|
  |           =* *+.|
  |        . = .B . |
  |       . o =E.. .|
  |        S .oo+o..|
  |          o ..*+.|
  |         .   +.=o|
  |             .o *|
  |           .o..++|
  +----[SHA256]-----+
  Generating public/private ecdsa key pair.
  Your identification has been saved in /etc/ssh/ssh_host_ecdsa_key.
  Your public key has been saved in /etc/ssh/ssh_host_ecdsa_key.pub.
  The key fingerprint is:
  SHA256:N3RTlPa7KU5ryq6kJAO8Tiq90ub4P1DGSofn6jFkM3k root@cloudimg
  The key's randomart image is:
  +---[ECDSA 256]---+
  |             .o. |
  |             .o  |
  |   o      . o. . |
  |  +.*    . . .  .|
  | .*XE   S o     .|
  | oo++    . .   . |
  | oo= o . .   .  o|
  |o.Oo. + o . .o.o |
  |oB=+.. . .o++o.  |
  +----[SHA256]-----+
  Generating public/private ed25519 key pair.
  Your identification has been saved in /etc/ssh/ssh_host_ed25519_key.
  Your public key has been saved in /etc/ssh/ssh_host_ed25519_key.pub.
  The key fingerprint is:
  SHA256:B6B/1SyUB/TFPfmU1ADIotnD+wjISO5L2JZkWe2lDUA root@cloudimg
  The key's randomart image is:
  +--[ED25519 256]--+
  |   .E .  o++.o+++|
  |     + ...++...++|
  |    o o=o.o.+  .o|
  |  .o oo=+o .    .|
  | o+o .+ So.      |
  | =o.o ....       |
  |..=    . o       |
  | o.     . .      |
  |  ..             |
  +----[SHA256]-----+
  sudo: unable to resolve host cloudimg: Resource temporarily unavailable
  Cloud-init v. 17.1 running 'modules:config' at Wed, 25 Oct 2017 13:24:39 +0000. Up 155.13 seconds.
  2017-10-25 13:24:40,289 - util.py[WARNING]: Failed to run command to import ubuntu ssh ids
  2017-10-25 13:24:40,291 - util.py[WARNING]: ssh-import-id failed for: ubuntu ['cyphermox']
  2017-10-25 13:24:40,292 - util.py[WARNING]: Running module ssh-import-id (<module 'cloudinit.config.cc_ssh_import_id' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_ssh_import_id.py'>) failed
  Cloud-init v. 17.1 running 'modules:final' at Wed, 25 Oct 2017 13:24:41 +0000. Up 156.51 seconds.
  ci-info: no authorized ssh keys fingerprints found for user ubuntu.
  Cloud-init v. 17.1 finished at Wed, 25 Oct 2017 13:24:41 +0000. Datasource DataSourceNoCloud [seed=/dev/vdb][dsmode=net].  Up 156.83 seconds

  
  This does not seem to be caused by ssh key generation (I tried to disable it, with no keytypes enabled there is still > 150 s delay), not does it seem to be related to the resizing operation.

  I suspect some other step requiring randomness to generate some kind
  of ID, but I don't know.

To manage notifications about this bug go to:
https://bugs.launchpad.net/cloud-init/+bug/1727358/+subscriptions