LXD container launch time

Hello to everyone.

I have a local available image which is called DetectionSvc and has a size of 2,5 GB.

When i am doing lxc launch DetectionSvc containerDetection the command finishes at a mean time of about 40 secs. Is this time ok ? I believe it is ok due to the large image. Is there a way to reduce this time without changing the image size ?

@stgraber

Hi!

You’ll need to figure out what keeps the image from launching faster. When you launch a new container, run lxc console on another terminal window so that you get a feel as to what takes up so much time.

Hi @simos . Thanks for the answer.
So as you say, is this launch time normal or not ?

Do we except a smaller amount of time ?

40s start time is quite a lot, assuming all these are on SSD.

But if you do not attempt to delve deeper and try to figure out why this container image launches in so much time, then you are out of luck.

You can compare with the launch time of a pristine Ubuntu container. This will help you have a benchmark as to how fast you can make your container go.

A pristine Ubuntu container takes about 5.3 seconds to start.
The ubuntu plain image is about 189 MB . Much smaller from the DetectionSvc

root@tkasidakis-HP-Pavilion-Gaming-Laptop-15-cx0xxx:~# lxc console DetectionSvc
To detach from the console, press: <ctrl>+a q
[ 4838.860813] cloud-init[192]: Cloud-init v. 20.2-45-g5f7825e2-0ubuntu1~18.04.1 running 'init' at Mon, 09 Nov 2020 12:13:34 +0000. Up 4.72 seconds.
[ 4838.860923] cloud-init[192]: ci-info: ++++++++++++++++++++++++++++++++++++++++++++++Net device info+++++++++++++++++++++++++++++++++++++++++++++++
[ 4838.860978] cloud-init[192]: ci-info: +--------+------+-------------------------------------------+-----------------+--------+-------------------+
[ 4838.861015] cloud-init[192]: ci-info: | Device |  Up  |                  Address                  |       Mask      | Scope  |     Hw-Address    |
[ 4838.861067] cloud-init[192]: ci-info: +--------+------+-------------------------------------------+-----------------+--------+-------------------+
[ 4838.861111] cloud-init[192]: ci-info: |  eth0  | True |                10.42.0.200                | 255.255.255.255 | global | 00:16:3e:69:81:ea |
[ 4838.861153] cloud-init[192]: ci-info: |  eth0  | True | fd42:b1c4:7e90:abc6:216:3eff:fe69:81ea/64 |        .        | global | 00:16:3e:69:81:ea |
[ 4838.861204] cloud-init[192]: ci-info: |  eth0  | True |        fe80::216:3eff:fe69:81ea/64        |        .        |  link  | 00:16:3e:69:81:ea |
[ 4838.861248] cloud-init[192]: ci-info: |   lo   | True |                 127.0.0.1                 |    255.0.0.0    |  host  |         .         |
[ 4838.861295] cloud-init[192]: ci-info: |   lo   | True |                  ::1/128                  |        .        |  host  |         .         |
[ 4838.861344] cloud-init[192]: ci-info: +--------+------+-------------------------------------------+-----------------+--------+-------------------+
[ 4838.861388] cloud-init[192]: ci-info: ++++++++++++++++++++++++++Route IPv4 info++++++++++++++++++++++++++
[ 4838.861427] cloud-init[192]: ci-info: +-------+-------------+-------------+---------+-----------+-------+
[ 4838.861471] cloud-init[192]: ci-info: | Route | Destination |   Gateway   | Genmask | Interface | Flags |
[ 4838.861511] cloud-init[192]: ci-info: +-------+-------------+-------------+---------+-----------+-------+
[ 4838.861544] cloud-init[192]: ci-info: |   0   |   0.0.0.0   | 169.254.0.1 | 0.0.0.0 |    eth0   |   UG  |
[ 4838.861579] cloud-init[192]: ci-info: +-------+-------------+-------------+---------+-----------+-------+
[ 4838.861624] cloud-init[192]: ci-info: ++++++++++++++++++++++++++++++++++Route IPv6 info++++++++++++++++++++++++++++++++++
[ 4838.861661] cloud-init[192]: ci-info: +-------+--------------------------+--------------------------+-----------+-------+
[ 4838.861696] cloud-init[192]: ci-info: | Route |       Destination        |         Gateway          | Interface | Flags |
[ 4838.861744] cloud-init[192]: ci-info: +-------+--------------------------+--------------------------+-----------+-------+
[ 4838.861777] cloud-init[192]: ci-info: |   0   | fd42:b1c4:7e90:abc6::/64 |            ::            |    eth0   |   Ue  |
[ 4838.861821] cloud-init[192]: ci-info: |   1   | fd42:b1c4:7e90:abc6::/64 |            ::            |    eth0   |   U   |
[ 4838.861872] cloud-init[192]: ci-info: |   2   |        fe80::/64         |            ::            |    eth0   |   U   |
[ 4838.861927] cloud-init[192]: ci-info: |   3   |           ::/0           | fe80::216:3eff:fe2e:f1cc |    eth0   |   UG  |
[ 4838.861991] cloud-init[192]: ci-info: |   5   |          local           |            ::            |    eth0   |   U   |
[ 4838.862043] cloud-init[192]: ci-info: |   6   |          local           |            ::            |    eth0   |   U   |
[ 4838.862083] cloud-init[192]: ci-info: |   7   |         ff00::/8         |            ::            |    eth0   |   U   |
[ 4838.862124] cloud-init[192]: ci-info: +-------+--------------------------+--------------------------+-----------+-------+
[  OK  ] Started Initial cloud-init job (metadata service crawler).
[  OK  ] Reached target Cloud-config availability.
[  OK  ] Reached target System Initialization.
[  OK  ] Started Daily Cleanup of Temporary Directories.
[  OK  ] Listening on Open-iSCSI iscsid Socket.
         Starting Socket activation for snappy daemon.
[  OK  ] Started Daily apt download activities.
[  OK  ] Listening on Unix socket for apport crash forwarding.
[  OK  ] Started Daily apt upgrade and clean activities.
[  OK  ] Listening on UUID daemon activation socket.
         Starting LXD - unix socket.
[  OK  ] Listening on ACPID Listen Socket.
[  OK  ] Started Message of the Day.
[  OK  ] Listening on D-Bus System Message Bus Socket.
[  OK  ] Started ACPI Events Check.
[  OK  ] Reached target Paths.
[  OK  ] Reached target Timers.
[  OK  ] Reached target Network is Online.
         Starting Availability of block devices...
[  OK  ] Reached target Remote File Systems (Pre).
[  OK  ] Reached target Remote File Systems.
[  OK  ] Listening on Socket activation for snappy daemon.
[  OK  ] Listening on LXD - unix socket.
[  OK  ] Reached target Sockets.
[  OK  ] Reached target Basic System.
         Starting System Logging Service...
         Starting LSB: automatic crash report generation...
         Starting Message of the Day...
         Starting LXD - container startup/shutdown...
         Starting Accounts Service...
         Starting Login Service...
         Starting Permit User Sessions...
[  OK  ] Started Deferred execution scheduler.
[  OK  ] Started D-Bus System Message Bus.
[  OK  ] Started Login Service.
[  OK  ] Started Unattended Upgrades Shutdown.
         Starting Snap Daemon...
[  OK  ] Started Regular background program processing daemon.
         Starting OpenBSD Secure Shell server...
         Starting Dispatcher daemon for systemd-networkd...
[  OK  ] Started System Logging Service.
[  OK  ] Started Availability of block devices.
[  OK  ] Started Permit User Sessions.
         Starting Authorization Manager...
         Starting Hold until boot process finishes up...
         Starting Terminate Plymouth Boot Screen...
[  OK  ] Started LSB: automatic crash report generation.
[  OK  ] Started Hold until boot process finishes up.
[  OK  ] Created slice system-getty.slice.
[  OK  ] Started Console Getty.
[  OK  ] Reached target Login Prompts.
[  OK  ] Started Terminate Plymouth Boot Screen.
[  OK  ] Started OpenBSD Secure Shell server.
[  OK  ] Started Authorization Manager.
[  OK  ] Started Accounts Service.
[  OK  ] Started Dispatcher daemon for systemd-networkd.
[  OK  ] Started Snap Daemon.
         Starting Wait until snapd is fully seeded...
[  OK  ] Started Wait until snapd is fully seeded.
         Starting Apply the settings specified in cloud-config...
[ 4840.969482] cloud-init[325]: Cloud-init v. 20.2-45-g5f7825e2-0ubuntu1~18.04.1 running 'modules:config' at Mon, 09 Nov 2020 12:13:38 +0000. Up 8.67 seconds.
[  OK  ] Started Apply the settings specified in cloud-config.
[  OK  ] Started LXD - container startup/shutdown.
[  OK  ] Reached target Multi-User System.
[  OK  ] Reached target Graphical Interface.
         Starting Update UTMP about System Runlevel Changes...
         Starting Execute cloud user/final scripts...
[  OK  ] Started Update UTMP about System Runlevel Changes.
[ 4842.582348] cloud-init[336]: Cloud-init v. 20.2-45-g5f7825e2-0ubuntu1~18.04.1 running 'modules:final' at Mon, 09 Nov 2020 12:13:40 +0000. Up 10.16 seconds.
[ 4842.582690] cloud-init[336]: Cloud-init v. 20.2-45-g5f7825e2-0ubuntu1~18.04.1 finished at Mon, 09 Nov 2020 12:13:40 +0000. Datasource DataSourceNoCloud [seed=/var/lib/cloud/seed/nocloud-net][dsmode=net].  Up 10.26 seconds
[  OK  ] Started Execute cloud user/final scripts.
[  OK  ] Reached target Cloud-init target.
         Starting Daily apt download activities...

Ubuntu 18.04.4 LTS DetectionSvc console

DetectionSvc login:          Stopping Accounts Service...
[  OK  ] Stopped Accounts Service.
         Starting Accounts Service...
[  OK  ] Started Accounts Service.
[  OK  ] Started Daily apt upgrade and clean activities

@simos this is the output of the lxc console DetectionSvc

My native Ubuntu installation is on my HDD. So i believe all of these are using my HDD not my SSD. Can anyone mention which are some good values for the launch time of containers ?

Both for an image of 189 MB ( plain ubuntu image ) and for a custom image of 2,5 GB.
Both images are available locally.

The 5.3s launch time for a container when you have a traditional disk look reasonable.

The lxc console output above show about 4s of output. The number at the start of the lines is the number of seconds since the boot of the kernel. Therefore, there are quite a few things going that we have not seen. Perhaps you can write a script to perform the launch and the run lxc console? The idea is to get an lxc console output that matches the 40s startup time that you are reporting. And you can visually observer the startup logs as to which services take so much time of the 40s startup time.

As you haven’t mentioned it, I assume that your storage pool is on ZFS. Is that the case?

My storage pool is dir . Should i change to zfs ? Is this going to make containers launch quickly ?

Anything other than dir would make the launch stage significantly faster by using copy-on-write rather than having to duplicate the entire data during creation.

You can see which steps are taking a long time by enabling debug mode and looking at the logs as you launch an instance:

sudo snap set lxd daemon.debug=true
sudo tail -f /var/snap/lxd/common/lxd/logs/lxd.log

Thanks a lot guys once again your help is something more than valuable.

I am starting to believe that dir was the problem reading this https://linuxcontainers.org/lxd/docs/master/storage.html

@tomp So first i am executing those 2 commands and then i am executing the launch command for the container ?

Yes thats correct, then look at the storage related logs, they will likely showing the time taken creating the volume as @stgraber suggested

When i did lxd init and choose zfs everything was ok but i forgot to do systemctl start snap.lxd.daemon so i unistall snap lxd and i i did again snap install lxd, lxd init

Would you like to use LXD clustering? (yes/no) [default=no]: no
Do you want to configure a new storage pool? (yes/no) [default=yes]: yes
Name of the new storage pool [default=default]: default
Name of the storage backend to use (btrfs, dir, lvm, zfs, ceph) [default=zfs]: zfs
Create a new ZFS pool? (yes/no) [default=yes]: yes
Would you like to use an existing empty block device (e.g. a disk or partition)? (yes/no) [default=no]: no
Size in GB of the new loop device (1GB minimum) [default=18GB]: 19GB
Would you like to connect to a MAAS server? (yes/no) [default=no]: no
Would you like to create a new local network bridge? (yes/no) [default=yes]: yes
What should the new bridge be called? [default=lxdbr0]: lxdbr0
What IPv4 address should be used? (CIDR subnet notation, “auto” or “none”) [default=auto]: auto
What IPv6 address should be used? (CIDR subnet notation, “auto” or “none”) [default=auto]: auto
Would you like LXD to be available over the network? (yes/no) [default=no]: yes
Address to bind LXD to (not including port) [default=all]: all
Port to bind LXD to [default=8443]: 8443
Trust password for new clients: 
Again: 
Would you like stale cached images to be updated automatically? (yes/no) [default=yes] yes
Would you like a YAML "lxd init" preseed to be printed? (yes/no) [default=no]: no
Error: Failed to create storage pool 'default': Failed to run: zpool create -f -m none -O compression=on default /var/snap/lxd/common/lxd/disks/default.img: cannot create 'default': pool already exists

Please help!!

If you’re sure there is nothing on your zpool default you can delete it and re-run lxd init.

Using:

zpool destroy default

Thanks a lot Thomas i fixed it.
I calculate the time needed for starting a container for a plain ubuntu 18.04 image.
I have zfs enabled.

The mean time was about 6.3 secs after repeat the launch operation 10 times.

I don’t notice any significant difference.

I will test how the things go with the 2,5GB image and the i will use the debug options.

DetectionSvc container launched siginifically faster. Especially the second time which i try the launch command. The first one took some time. Maybe because the used image was an image which had been imported from a tar.gz

root@tkasidakis-HP-Pavilion-Gaming-Laptop-15-cx0xxx:~/Desktop sudo tail -f /var/snap/lxd/common/lxd/logs/lxd.log
t=2020-11-10T14:12:57+0200 lvl=info msg="Starting container" action=start created=2020-11-10T14:11:15+0200 ephemeral=false name=DetectionSvc project=default stateful=false used=1970-01-01T02:00:00+0200
t=2020-11-10T14:12:59+0200 lvl=info msg="Started container" action=start created=2020-11-10T14:11:15+0200 ephemeral=false name=DetectionSvc project=default stateful=false used=1970-01-01T02:00:00+0200
t=2020-11-10T14:13:49+0200 lvl=info msg="Shutting down container" action=shutdown created=2020-11-10T14:11:15+0200 ephemeral=false name=DetectionSvc project=default timeout=-1s used=2020-11-10T14:12:58+0200
t=2020-11-10T14:13:53+0200 lvl=info msg="Shut down container" action=shutdown created=2020-11-10T14:11:15+0200 ephemeral=false name=DetectionSvc project=default timeout=-1s used=2020-11-10T14:12:58+0200
t=2020-11-10T14:14:07+0200 lvl=info msg="Deleting container" created=2020-11-10T14:11:15+0200 ephemeral=false name=DetectionSvc project=default used=2020-11-10T14:12:58+0200
t=2020-11-10T14:14:07+0200 lvl=info msg="Deleted container" created=2020-11-10T14:11:15+0200 ephemeral=false name=DetectionSvc project=default used=2020-11-10T14:12:58+0200
t=2020-11-10T14:15:35+0200 lvl=info msg="Creating container" ephemeral=false name=DetectionSvc project=default
t=2020-11-10T14:15:35+0200 lvl=info msg="Created container" ephemeral=false name=DetectionSvc project=default
t=2020-11-10T14:15:43+0200 lvl=info msg="Starting container" action=start created=2020-11-10T14:15:35+0200 ephemeral=false name=DetectionSvc project=default stateful=false used=1970-01-01T02:00:00+0200
t=2020-11-10T14:15:43+0200 lvl=info msg="Started container" action=start created=2020-11-10T14:15:35+0200 ephemeral=false name=DetectionSvc project=default stateful=false used=1970-01-01T02:00:00+0200

@tomp I am not sure if i am using the tailf -f command properly

Creating DetectionSvc
Starting DetectionSvc
8.604377508163452
Creating DetectionSvc
Starting DetectionSvc
8.055083513259888
Creating DetectionSvc
Starting DetectionSvc
7.500951528549194
Creating DetectionSvc
Starting DetectionSvc
7.951788425445557
Creating DetectionSvc
Starting DetectionSvc
8.447054386138916
Creating DetectionSvc
Starting DetectionSvc
7.7724690437316895
Creating DetectionSvc
Starting DetectionSvc
7.672643184661865
Creating DetectionSvc
Starting DetectionSvc
8.600577354431152
Creating DetectionSvc
Starting DetectionSvc
8.703813791275024
Creating DetectionSvc
Starting DetectionSvc
9.426559448242188
======== max ===============
9.426559448242188
=============================
======== min ===============
7.500951528549194
============================
======== mean ===============
8.273531818389893
============================
======== median ===============
8.251068949699402
==============================
======== variance ===============
0.34682142860630544
================================

Is there a way to start a container with restricted resources ? If so, is this going to affect the launch time ??

If you’re only interested in startup time, rather than which steps are taking the time, then what you’re doing is fine. But in order to see which steps are taking the time you need to enable debug logging:

sudo snap set lxd daemon.debug=true
sudo systemctl reload snap.lxd.daemon

Thanks a lot

So do you believe the above measurements are OK ?

The steps to have a good debug logging are :

  1. sudo snap set lxd daemon.debug=true

  2. sudo systemctl reload snap.lxd.daemon

  3. sudo lxc launch DetectionSvc DetectionSvc

right ?

I’m not sure what you are trying to test, are you trying to test the launch time of a container on a dir or zfs pool, with or without the initial image being download first?