LXD container launch time

OK sorry for the mess, i will make it more clear

tkasidakis@tkasidakis-HP-Pavilion-Gaming-Laptop-15-cx0xxx:~$ sudo lxc image list
+--------------+--------------+--------+---------------------------------------------+--------------+-----------+-----------+-------------------------------+
|    ALIAS     | FINGERPRINT  | PUBLIC |                 DESCRIPTION                 | ARCHITECTURE |   TYPE    |   SIZE    |          UPLOAD DATE          |
+--------------+--------------+--------+---------------------------------------------+--------------+-----------+-----------+-------------------------------+
| DetectionSvc | 6e6260b3414a | no     | Ubuntu 18.04 LTS server (20200722)          | x86_64       | CONTAINER | 2389.11MB | Nov 10, 2020 at 12:08pm (UTC) |
+--------------+--------------+--------+---------------------------------------------+--------------+-----------+-----------+-------------------------------+
|              | 6063f2011ba1 | no     | ubuntu 18.04 LTS amd64 (release) (20201031) | x86_64       | CONTAINER | 189.70MB  | Nov 10, 2020 at 11:28am (UTC) |
+--------------+--------------+--------+---------------------------------------------+--------------+-----------+-----------+-------------------------------+

The above measurements are derived from doing

sudo lxc launch DetectionSvc DetectionSvc

When i did

lxd init

i choose zfs as storage policy

Are the above measurements OK as far as the launch time is concerned. Is there a way to reduce the above numbers ? Maybe if i start the container with limited resources ?

I want to achieve as smaller launch time as i can with the DetectionSvc image.

If you’re starting from a fresh LXD each time, then 8 seconds to download the container image and start seems pretty good.

Do subsequent lxc start <container> take as long after doing lxc stop <container>?

So is that image being download or is it local? Is this the first time you have a launched a container on that storage pool? If so then it will be unpacking the image tarball onto the ZFS pool before creating an optimized snapshot which will be used to create subsequent containers from the same image.

The image is local. The first time which i launched the container took a lot, meaning the first time launching a container under zfs storage pool. All the other times took more or less 8 seconds. I dont have many containers. The container is one . DetectionSvc .

After the creation, i stop the container and then i am deleteting.
All this operations have a significant time gap among them.

So should i stick with the 8 seconds as a good number which can not be reduced further more right ?

No that is not a good time, here is a test on my local PC (nothing special, sata SSD drive using a non-optimized loopback image ZFS pool).

The images:ubuntu/focal image is already downloaded locally, so my internet speed doesn’t factor into it.

# Create fresh ZFS storage pool using a loopback image onto the host's filesystem (not very performant compared to using a dedicated driver/partition)
lxc storage create zfstest zfs
Storage pool zfstest created

# Create new container on new pool, this will unpack the image into a ZFS volume and then snapshot it for creating containers from. But won't start the container.
time lxc init images:ubuntu/focal ctest1 -s zfstest
Creating ctest1
                                          
real	0m5.890s
user	0m0.052s
sys	0m0.012s

# Start the container.
time lxc start ctest1

real	0m0.405s
user	0m0.014s
sys	0m0.008s

# Delete the container
lxc delete -f ctest1

# Recreate the container (using the existing optimized snapshot volume):
time lxc init images:ubuntu/focal ctest1 -s zfstest
Creating ctest1

real	0m0.614s
user	0m0.055s
sys	0m0.015s

So you can see even on my not partcularly fast system, it is performing must faster than your tests.

I would suggest you enable debug logging and see which steps are taking longest. Also ensure you differentiate between lxc init (which creates a container) and lxc start which starts a container.

The lxc launch command does both a create and a start in one go. So not useful for testing.

To tell you the truth, I am a little bit confused . I understand fully your example, but is the launch command so bad that produces so bad times ?

In my case, i want exactly this : both creation and start of a container.

If i add your measured time above is way far from 8,2 secs.

The same operation as yours in my laptop ( meaning starting a container from a plain ubuntu image which is available locally so network is omitted) takes about 5 secs .

The fact that i am using HDD can cause some much overhead ?

No the launch command is fine to use.

What I was trying to explain was that if you are trying to find the cause of the slow down you would be better off using lxc init and then lxc start and seeing which one introduces the slow down.

You need to use the debug log output to diagnose the issue further im afraid. Otherwise we are just guessing.

Yes yes i will used it definitely Thomas. I am just waiting to upload the DetectionSvc.tar.gz to a VM which has CentOS and is quite powerfull in order to see the behavior of launch command there. I will be back with a detailed post and debugging info refering also to the platform that i used :slight_smile:

1 Like

@tomp Can you explain me what do we mean with the optimized snapshot volume ?

How we achieve so big time gain from 5 seconds to 0.6 secs ?

Take a look at which explains it https://linuxcontainers.org/lxd/docs/master/storage#optimized-image-storage

1 Like

Ok thanks a lot.

root@tkasidakis-HP-Pavilion-Gaming-Laptop-15-cx0xxx:~/Desktop time lxc launch DetectionSvc DetectionSvc -s zfstest
Creating DetectionSvc
Error: not found

real	0m0,057s
user	0m0,030s
sys	0m0,031s

Any help with this ?

Suggests either the image or storage pool not found.

1 Like

Obviously because i have note create the stprage pool :slight_smile:

@tomp

The init procedure of the DetectionSvc container took about 2 secs.
The start procedure of the DetectionSvc container took about 6 secs.
When i perform launch command, it took 8 secs which seems reasonable.

Thomas i did exactly what you did with zfstest but it didn’t improve my times.

I believe that the fact that i am using HDD instead of SSD doesn’t help me with my time measurements.

root@tkasidakis-HP-Pavilion-Gaming-Laptop-15-cx0xxx:~/Desktop sudo snap set lxd daemon.debug=true
root@tkasidakis-HP-Pavilion-Gaming-Laptop-15-cx0xxx:~/Desktop sudo systemctl reload snap.lxd.daemon
root@tkasidakis-HP-Pavilion-Gaming-Laptop-15-cx0xxx:~/Desktop  lxc launch DetectionSvc DetectionSvc
Creating DetectionSvc
Starting DetectionSvc
root@tkasidakis-HP-Pavilion-Gaming-Laptop-15-cx0xxx:~/Desktop# sudo tail -f /var/snap/lxd/common/lxd/logs/lxd.log
t=2020-11-12T14:07:34+0200 lvl=dbug msg="MountInstance finished" driver=zfs instance=DetectionSvc pool=default project=default
t=2020-11-12T14:07:34+0200 lvl=info msg="Starting container" action=start created=2020-11-12T14:07:19+0200 ephemeral=false name=DetectionSvc project=default stateful=false used=1970-01-01T02:00:00+0200
t=2020-11-12T14:07:34+0200 lvl=dbug msg=Handling ip=@ method=GET protocol=unix url=/internal/containers/56/onstart username=root
t=2020-11-12T14:07:34+0200 lvl=dbug msg="MountInstance started" driver=zfs instance=DetectionSvc pool=default project=default
t=2020-11-12T14:07:34+0200 lvl=dbug msg="MountInstance finished" driver=zfs instance=DetectionSvc pool=default project=default
t=2020-11-12T14:07:35+0200 lvl=dbug msg="Scheduler: container DetectionSvc started: re-balancing" 
t=2020-11-12T14:07:35+0200 lvl=info msg="Started container" action=start created=2020-11-12T14:07:19+0200 ephemeral=false name=DetectionSvc project=default stateful=false used=1970-01-01T02:00:00+0200
t=2020-11-12T14:07:35+0200 lvl=dbug msg="Success for task operation: 305b2079-96e0-41aa-9b62-ac137b50bc4f" 
t=2020-11-12T14:07:35+0200 lvl=dbug msg="Event listener finished: 86b8431d-18b9-4eb3-8938-d442cd0f18d5" 
t=2020-11-12T14:07:35+0200 lvl=dbug msg="Disconnected event listener: 86b8431d-18b9-4eb3-8938-d442cd0f18d5"  

I also wanted to ask if the the resources which belong to a container can affect launch time.

If we decrease cpu and memory usage is there a chance to reduce launch time ?

These are good questions and indeed it is likely that they affect launch time.
However, the real issue is how much of an effect it has to the launch time.
That is, is the launch time difference that significant so that you would need to consider to adjust cpu and memory for a container?

You can easily test these and make a table of the results. In fact it would be good to get the results here. You can put the results in a table in Markdown by following this generator, https://www.tablesgenerator.com/markdown_tables

1 Like

I will do it definitely simos. In order to have fair results i should adjust a profile with the specific limits. I want to put to a profile the minimum cpu and memory limits in order to start the container. Can you help me a bit with this please ?

Is there a way to combine the default profile with a profile which makes a container to have limited resources ?

Something like

lxc launch ubuntu:18.04 LimitedC1 --profile default --profile limited_resources

Those logs are not showing which part is taking the time. It suggests you are missing the important bits before “MountInstance finished”.

For example if I run lxc launch images:ubuntu/focal c1 I see many lines, but these are the important parts that occur after the imagr has been download, but as it is being unpacked into the first ZFS volume to create the optimized volume to create the first container from.

DBUG[11-12|16:35:56] Image "1a26d556e3e08a98f0668ad06535209b19dbd76bb49118269508ddec22e5529c" already exists in the DB 
INFO[11-12|16:35:56] Creating container                       project=default name=c1 ephemeral=false
INFO[11-12|16:35:56] Created container                        project=default name=c1 ephemeral=false
DBUG[11-12|16:35:56] CreateInstanceFromImage started          driver=zfs pool=zfs project=default instance=c1
DBUG[11-12|16:35:56] EnsureImage started                      driver=zfs pool=zfs fingerprint=1a26d556e3e08a98f0668ad06535209b19dbd76bb49118269508ddec22e5529c
DBUG[11-12|16:35:56] Database error: &errors.errorString{s:"No such object"} 
DBUG[11-12|16:35:56] Mounted ZFS dataset                      driver=zfs pool=zfs path=/var/lib/lxd/storage-pools/zfs/images/1a26d556e3e08a98f0668ad06535209b19dbd76bb49118269508ddec22e5529c dev=zfs/images/1a26d556e3e08a98f0668ad06535209b19dbd76bb49118269508ddec22e5529c
DBUG[11-12|16:35:56] Running filler function                  driver=zfs pool=zfs path=/var/lib/lxd/storage-pools/zfs/images/1a26d556e3e08a98f0668ad06535209b19dbd76bb49118269508ddec22e5529c dev=
DBUG[11-12|16:35:56] Updated metadata for task Operation: acdecaea-0461-49a3-90e2-123261728d60 
DBUG[11-12|16:36:01] Unmounted ZFS dataset                    driver=zfs pool=zfs dev=zfs/images/1a26d556e3e08a98f0668ad06535209b19dbd76bb49118269508ddec22e5529c path=/var/lib/lxd/storage-pools/zfs/images/1a26d556e3e08a98f0668ad06535209b19dbd76bb49118269508ddec22e5529c
DBUG[11-12|16:36:01] Database error: &errors.errorString{s:"No such object"} 
DBUG[11-12|16:36:01] EnsureImage finished                     driver=zfs pool=zfs fingerprint=1a26d556e3e08a98f0668ad06535209b19dbd76bb49118269508ddec22e5529c
DBUG[11-12|16:36:01] Checking volume size                     driver=zfs pool=zfs project=default instance=c1
DBUG[11-12|16:36:01] Mounted ZFS dataset                      driver=zfs pool=zfs dev=zfs/containers/c1 path=/var/lib/lxd/storage-pools/zfs/containers/c1
DBUG[11-12|16:36:01] Unmounted ZFS dataset                    driver=zfs pool=zfs path=/var/lib/lxd/storage-pools/zfs/containers/c1 dev=zfs/containers/c1
DBUG[11-12|16:36:01] CreateInstanceFromImage finished         driver=zfs pool=zfs project=default instance=c1
DBUG[11-12|16:36:01] UpdateInstanceBackupFile started         driver=zfs pool=zfs instance=c1 project=default
DBUG[11-12|16:36:01] Mounted ZFS dataset                      driver=zfs pool=zfs dev=zfs/containers/c1 path=/var/lib/lxd/storage-pools/zfs/containers/c1
DBUG[11-12|16:36:01] Unmounted ZFS dataset                    driver=zfs pool=zfs dev=zfs/containers/c1 path=/var/lib/lxd/storage-pools/zfs/containers/c1
DBUG[11-12|16:36:01] UpdateInstanceBackupFile finished        driver=zfs pool=zfs instance=c1 project=default
DBUG[11-12|16:36:01] Success for task operation: acdecaea-0461-49a3-90e2-123261728d60 
DBUG[11-12|16:36:01] Handling                                 url=/1.0/instances/c1 ip=@ username=user protocol=unix method=GET
DBUG[11-12|16:36:01] Handling                                 method=PUT url=/1.0/instances/c1/state ip=@ username=user protocol=unix
DBUG[11-12|16:36:01] New task Operation: adbb059d-78c4-4a3a-9002-776dc244d896 
DBUG[11-12|16:36:01] Started task operation: adbb059d-78c4-4a3a-9002-776dc244d896 
DBUG[11-12|16:36:01] MountInstance started                    driver=zfs pool=zfs project=default instance=c1
DBUG[11-12|16:36:01] Mounted ZFS dataset                      driver=zfs pool=zfs dev=zfs/containers/c1 path=/var/lib/lxd/storage-pools/zfs/containers/c1
DBUG[11-12|16:36:01] MountInstance finished                   driver=zfs pool=zfs project=default instance=c1
DBUG[11-12|16:36:01] Starting device                          device=eth0 type=nic project=default instance=c1
DBUG[11-12|16:36:01] Scheduler: network: vethbd41dfee has been added: updating network priorities 
DBUG[11-12|16:36:01] Scheduler: network: veth3e88b610 has been added: updating network priorities 
DBUG[11-12|16:36:01] Starting device                          device=root type=disk project=default instance=c1
DBUG[11-12|16:36:01] UpdateInstanceBackupFile started         driver=zfs pool=zfs project=default instance=c1
DBUG[11-12|16:36:01] UpdateInstanceBackupFile finished        driver=zfs pool=zfs project=default instance=c1
INFO[11-12|16:36:01] Starting container                       project=default name=c1 action=start created=2020-11-12T16:35:56+0000 ephemeral=false used=1970-01-01T01:00:00+0100 stateful=false
DBUG[11-12|16:36:01] Handling                                 method=GET url=/internal/containers/198/onstart ip=@ username=root protocol=unix
DBUG[11-12|16:36:01] Scheduler: container c1 started: re-balancing 
INFO[11-12|16:36:01] Started container                        ephemeral=false used=1970-01-01T01:00:00+0100 stateful=false project=default name=c1 action=start created=2020-11-12T16:35:56+0000
1 Like