Subcloud failed to unlock post data migration - docker and registry sizes were increased prior to upgrade

[Heitor Matsui]

Brief Description
-----------------
Subcloud fails to unlock post data migration. Prior to the upgrade from 21.05 -> 21.12, docker-distribution (registry) size was increased from 16G to 32G and docker from 30G to 40G.

Severity
-----------------
Critical - failure is unrecoverable with upgrade retry

Steps to Reproduce
-----------------
DC + 2 subclouds

Subcloud 1
Increase docker size from 30G to 40G
Increase docker-distribution size from 16G to 32G

Subcloud 2
Keep default docker and docker-distribution sizes

Prestage the 2 subclouds
Upgrade the 2 subclouds

Expected Behavior
-----------------
Both subclouds are upgraded successfully

Actual Behavior
-----------------
Subcloud 1 failed to unlock

Reproducibility
-----------------
Reproducible

System Configuration
-----------------
Distributed Cloud

Branch/Pull Time/Commit
-----------------
master

Last Pass
-----------------
This likely is a test escape

Timestamp/Logs
-----------------
2022-03-23-22-46-58_aio/puppet.log:2022-03-23T22:49:14.876 Error: 2022-03-23 22:49:14 +0000 Execution of '/usr/sbin/lvextend -L 26214400k /dev/cgts-vg/backup-lv' returned 5: Insufficient free space: 768 extents needed, but only 453 available
2022-03-23-22-46-58_aio/puppet.log:2022-03-23T22:49:14.972 Error: 2022-03-23 22:49:14 +0000 /Stage[main]/Platform::Filesystem::Backup/Platform::Filesystem[backup-lv]/Logical_volume[backup-lv]/size: change from 1G to 25G failed: Execution of '/usr/sbin/lvextend -L 26214400k /dev/cgts-vg/backup-lv' returned 5: Insufficient free space: 768 extents needed, but only 453 available

Test Activity
-----------------
Feature Testing

Workaround
-----------------
None

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.opendev.org/c/starlingx/config/+/837002

[Heitor Matsui (heitormatsui)]

From the investigation:

1. docker-distribution filesystem gets resized:
2022-03-23T19:26:30.000 controller-0 -sh: info HISTORY: PID=1996892 UID=42425 system controllerfs-modify docker-distribution=32

2. docker filesystem gets resized (while docker-distribution is still being resized):
2022-03-23T19:27:49.000 controller-0 -sh: info HISTORY: PID=1996892 UID=42425 system host-fs-modify controller-0 docker=40

3. system allows both resizes, and update the database accordingly:
COPY controller_fs (created_at, updated_at, deleted_at, id, uuid, forisystemid, state, name, size, logical_volume, replicated) FROM stdin;
2022-03-14 19:55:26.723258 2022-03-16 18:07:58.923396 \N 1 35bd59fd-318c-4a4a-942f-847bc8fb3fcb 1 available platform 10 platform-lv t
2022-03-14 19:55:26.732183 2022-03-16 18:07:58.929855 \N 2 d1dfe972-2f2f-4ffe-9c73-e4216d0d635e 1 available database 10 pgsql-lv t
2022-03-14 19:55:26.737461 2022-03-16 18:07:58.93653 \N 3 4e66b2bf-5a52-4dfd-945b-c2c6d8c5207e 1 available extension 1 extension-lv t
2022-03-14 19:55:26.742988 2022-03-16 18:07:58.942695 \N 4 4de4b280-878c-4e7e-ae0a-e065d9069749 1 available etcd 5 etcd-lv t
2022-03-14 19:55:26.74801 2022-03-23 19:26:55.295305 \N 5 16c12569-2096-4835-b2c7-628ef77d2619 1 available docker-distribution 32 dockerdistribution-lv t
\.

COPY host_fs (created_at, updated_at, deleted_at, id, uuid, name, size, logical_volume, forihostid) FROM stdin;
2022-03-14 19:55:41.309528 \N \N 1 441e92b2-5cc6-4fc6-841a-e991cff70c9e scratch 16 scratch-lv 1
2022-03-14 19:55:41.31728 \N \N 2 9a6e5247-5afa-48ba-9f9e-34e545797dcd backup 25 backup-lv 1
2022-03-14 19:55:41.327922 \N \N 4 55e08400-2217-4f67-95d2-bc0076ad60f9 kubelet 10 kubelet-lv 1
2022-03-14 19:55:41.322658 2022-03-23 19:27:51.374653 \N 3 4561e38d-60a6-4998-8b6b-9c7b40b3a304 docker 40 docker-lv 1
\.

4. But the resize for docker filesystem doesn't happen, since cgts-vg didn't have enough space prior to the commands (observe docker filesystem with 30G):
--------------------------------------------------------------------
Wed Mar 23 20:38:21 UTC 2022 : : lsblk
--------------------------------------------------------------------
NAME MAJ:MIN RM SIZE RO TYPE MOUNTPOINT
nvme0n1 259:0 0 1.8T 0 disk
├─nvme0n1p1 259:2 0 29.3G 0 part /opt/platform-backup
├─nvme0n1p2 259:3 0 300M 0 part /boot/efi
├─nvme0n1p3 259:4 0 500M 0 part /boot
├─nvme0n1p4 259:5 0 19.5G 0 part /
└─nvme0n1p5 259:6 0 179G 0 part
  ├─cgts--vg-scratch--lv 253:0 0 16G 0 lvm /scratch
  ├─cgts--vg-log--lv 253:1 0 7.8G 0 lvm /var/log
  ├─cgts--vg-extension--lv 253:2 0 1G 0 lvm
  │ └─drbd5 147:5 0 1024M 0 disk /opt/extension
  ├─cgts--vg-pgsql--lv 253:3 0 20G 0 lvm
  │ └─drbd0 147:0 0 20G 0 disk /var/lib/postgresql
  ├─cgts--vg-docker--lv 253:4 0 30G 0 lvm /var/lib/docker
  ├─cgts--vg-kubelet--lv 253:5 0 10G 0 lvm /var/lib/...

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/c/starlingx/config/+/837002
Committed: https://opendev.org/starlingx/config/commit/e4c2191324f9616e5dc59eb17fc7ecc9f6ee17d9
Submitter: "Zuul (22348)"
Branch: master

commit e4c2191324f9616e5dc59eb17fc7ecc9f6ee17d9
Author: Heitor Matsui <email address hidden>
Date: Thu Apr 7 14:20:21 2022 -0300

    Block host-fs resize if a drbd-fs is being resized

    While a controllerfs is resizing, the cgts-vg available size
    is not yet updated with the resulting available size after the resize,
    so, during this period, a host-fs resize can be executed in parallel,
    but may fail if cgts-vg doesn't have enough space for both resizes
    (and puppet runtime won't return a failure because of [1]). As a
    consequence, the host-fs size will be updated on the database,
    even though is is not resized in fact.

    This commit blocks host-fs resizes to be executed if a controllerfs
    resize is running, allowing them to be executed only when the
    latter finishes and thus the available size is updated on the database.

    [1] https://opendev.org/starlingx/stx-puppet/src/branch/master/puppet-manifests/src/modules/platform/manifests/filesystem.pp#L146

    Test Plan:
    PASS: Execute controllerfs-modify
          Execute host-fs-modify when status=drbd_fs_resizing_in_progress
          Verify that system blocks the host-fs-modify command
    PASS: Execute host-fs-modify with no controllerfs being resized
          Verify that host-fs-modify command running as usual
    PASS: Fresh install, bootstrap and configuration
    PASS: Run backup and restore successfully
    PASS: Upgrade AIO SX successfully

    Closes-bug: 1968201
    Change-Id: I0285d1856d76cdbc36e5abc761ea01f1df33b09d
    Signed-off-by: Heitor Matsui <email address hidden>

[Heitor Matsui (heitormatsui)]

Moving again to In Progress since an additional fix needs to be submitted, for commands run in sequence and in a very short interval (< 1 minute) in the following order:

1. host-fs-modify -> controllerfs-modify OR
2. host-fs-modify -> host-fs-modify

[Heitor Matsui (heitormatsui)]

As of today the system fs commands, depending on the order, allow the user to run multiple commands in a sequence, even if there isn't enough space left on the host cgts-vg.

The following example shows a scenario where cgts-vg has 16GB available, but it allowed increasing docker host-fs in an AIO-SX deployment from 30 to 80GB (+50GB) in five chunks of 10GB:

[sysadmin@controller-0 ~(keystone_admin)]$ s
[sysadmin@controller-0 ~(keystone_admin)]$ SIZE=30
s [sysadmin@controller-0 ~(keystone_admin)]$ s host-lvg-list controller-0
+--------------------------------------+------------+-------------+--------+------------------+------------------+-------------+-------------+
| UUID | LVG Name | State | Access | Total Size (GiB) | Avail Size (GiB) | Current PVs | Current LVs |
+--------------------------------------+------------+-------------+--------+------------------+------------------+-------------+-------------+
| 14665345-ea19-415a-a0d0-7efcab837ace | cgts-vg | provisioned | wz--n- | 178.968 | 16.156 | 1 | 12 |
| 504332be-e8ef-4753-8937-575e3ef4f16e | nova-local | provisioned | wz--n- | 10.996 | 0.0 | 1 | 1 |
+--------------------------------------+------------+-------------+--------+------------------+------------------+-------------+-------------+
[sysadmin@controller-0 ~(keystone_admin)]$ for I in $(seq 5); do date; s host-fs-modify controller-0 docker=$(( SIZE + (10 * I) )); sleep 3; done
Qua Abr 6 20:13:11 UTC 2022
+--------------------------------------+---------+-------------+----------------+
| UUID | FS Name | Size in GiB | Logical Volume |
+--------------------------------------+---------+-------------+----------------+
| 535e4841-e3d7-42d9-a441-2be9499aadb6 | backup | 25 | backup-lv |
| 38d2bf0a-1489-4fb5-9119-cd588b3f0649 | docker | 40 | docker-lv |
| 2ad5d50c-b4af-48de-bfbf-be856e1c27d7 | kubelet | 10 | kubelet-lv |
| f536231f-2135-48ff-bf01-da941821121e | scratch | 16 | scratch-lv |
+--------------------------------------+---------+-------------+----------------+
Qua Abr 6 20:13:19 UTC 2022
+--------------------------------------+---------+-------------+----------------+
| UUID | FS Name | Size in GiB | Logical Volume |
+--------------------------------------+---------+-------------+----------------+
| 535e4841-e3d7-42d9-a441-2be9499aadb6 | backup | 25 | backup-lv |
| 38d2bf0a-1489-4fb5-9119-cd588b3f0649 | docker | 50 | docker-lv |
| 2ad5d50c-b4af-48de-bfbf-be856e1c27d7 | kubelet | 10 | kubelet-lv |
| f536231f-2135-48ff-bf01-da941821121e | scratch | 16 | scratch-lv |
+--------------------------------------+---------+-------------+----------------+
Qua Abr 6 20:13:26 UTC 2022
+--------------------------------------+---------+-------------+----------------+
| UUID | FS Name | Size in GiB | Logical Volume |
+--------------------------------------+---------+-------------+----------------+
| 535e4841-e3d7-42d...

[Heitor Matsui (heitormatsui)]

The agent audit reports back lvg data to conductor based on the output of the vgdisplay command, so it reflects in fact the final state of the filesystem on the target host of the agent.

It would be good to increase the robustness of the agent audit, so that it reports back to conductor if there are any inconsistencies between the configured host-fs on the target hosts and the database values, but this won't be treated in the scope of this bug.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.opendev.org/c/starlingx/config/+/839384

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/c/starlingx/config/+/839384
Committed: https://opendev.org/starlingx/config/commit/8c3ebd9def38c586143abc37b6aab6b30f630e4f
Submitter: "Zuul (22348)"
Branch: master

commit 8c3ebd9def38c586143abc37b6aab6b30f630e4f
Author: Heitor Matsui <email address hidden>
Date: Tue Apr 26 10:24:07 2022 -0300

    Block filesystem resizes if waiting for agent to report

    Currently the system may allow multiple host-fs-modify commands
    to be executed in sequence and in a short interval even if these
    would consume more space than is available in the volume group.
    This is caused because the volume group available space is updated
    by the agent audit, on [1], which runs every minute, so every
    fs resize command that is executed before the agent reports back
    will be allowed to run and will update the fs size on the database,
    leaving an inconsistent value, since when the puppet manifest runs
    on the host it will fail with "not enough space" error (but won't
    fail the manifest as return code 5 is allowed on [2], which is
    the return code for this error, as can be observed on [3]).

    The scenarios affected by the behavior described previously are:
    host-fs-modify -> controllerfs-modify
    host-fs-modify -> host-fs-modify

    This commit adds an extra validation before allowing both "fs-modify"
    commands to run, that compares the most recent host-fs "updated_at"
    date with the cgts-vg "updated_at" date stored on the database, only
    allowing the commands to run if the latter is greater than the former.

    Test Plan:
    PASS: run host-fs-modify command successfully and shortly after run
          another host-fs-modify command and verify that it is blocked
          from running
    PASS: run host-fs-modify command successfully and shortly after run
          a controllerfs-modify command and verify that it is blocked
          from running
    PASS: run host-fs-modify command successfully, wait for lvg available
          size to be updated and run another host-fs-modify, verify that
          it runs successfully
    PASS: run host-fs-modify command successfully, wait for lvg available
          size to be updated and run a controllerfs-modify, verify that
          it runs successfully
    PASS: resize host-fs and controllerfs before upgrade, upgrade subcloud
          and verify that upgrade runs successfully

    Regression:
    PASS: run host-fs-modify command that exceeds vg available space and
          verify that it is not allowed to execute
    PASS: run controllerfs-modify command that exceeds vg available space
          and verify that it is not allowed to execute

    [1] https://opendev.org/starlingx/config/src/branch/master/sysinv/sysinv/sysinv/sysinv/agent/manager.py#L1421
    [2] https://opendev.org/starlingx/stx-puppet/src/branch/master/puppet-manifests/src/modules/platform/manifests/filesystem.pp#L146
    [3] https://paste.opendev.org/show/bswm7v3Qj2cpiD2H9O3j/

    Closes-bug: 1968201
    Change-Id: Ifc2fb272f3762441cc0c7755443f01d9789f8723
    Signed-off-by: Heitor Matsui <email address hidden>...