Race with local file systems can make open-vm-tools fail to start

Note: IMHO a consequence of the bad fix (in Debian) to bug 1667831

So, definitely using the

After=local-fs.target

is a sane fix to ensuring that the local filesystem is mounted before starting.

I'm interested in understanding why the open-vm-tools needs to run before cloud-init. specifically, what's wrong with:

After=cloud-init.service

which is when more of the system is up.

I'll fix the current known race for now.

@Rharper - I guided the original author of the change to the bug 1667831 here.
@Sankar - I hope you can answer Ryans question.

I tested the fix a bit more, always worked for me, that said I'll:

1. upload something to the ppa of the xenial backport (it is a ppa, we can iterate fast there)
2. I consider Ryans check an ack to an MP (and it is the only change), so I'll fastpath that change and upload to bionic
3. report the issue to Debian to get their opinion and the chance to at some point sync again.

cloud-init task was just for discussion, marking it invalid to make clear there is no cloud-init action needed.

1. I updated the ppa we test for a potential xenial-backport.
   It now has 10.2.0-3ubuntu0.16.04.1~ppa2 with the fix applied

2. Pushed said fix to Bionic [1] (need to check proposed migration)

3. reported the same to Debian, but then found [2] and chimed in there

[1]: https://launchpad.net/ubuntu/+source/open-vm-tools/2:10.2.0-3ubuntu1
[2]: https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=888955

This bug was fixed in the package open-vm-tools - 2:10.2.0-3ubuntu1

---------------
open-vm-tools (2:10.2.0-3ubuntu1) bionic; urgency=medium

  * d/open-vm-tools.service: Add After=local-fs.target dependency ensuring
    filesystems are ready to fix a race on startup (LP: #1750780)

 -- Christian Ehrhardt <email address hidden> Thu, 22 Feb 2018 08:39:26 +0100

I dont think I really agree with this fix.

Adding 'After=local-fs.target' essentially pushes cloud-init to have that same dependency, which it does not have. We don't really want cloud-init to have to wait for local-fs.target.
For example see bug 1691489 (and related fallout bug 1717477).

If the only reason for local-fs.target was actually PrivateTmp, then there is a bug in systemd.

https://www.freedesktop.org/software/systemd/man/systemd.exec.html
 | Implicit Dependencies
 | Similar, units with PrivateTmp= enabled automatically get mount unit
 | dependencies for all mounts required to access /tmp and /var/tmp. They
 | will also gain an automatic After= dependency on systemd-tmpfiles-
 | setup.service(8).

 So there must have been a different read-only filesystem involved.

While I can follow your argument of "it should work" I tested and if I drop 'After=local-fs.target' I'm in bad state again. If from this state I disable PrivateTmp it works as well.
So it is PrivateTmp even though the documentation you linked says it should not.

I wondered if that might only be for the older systemd in Xenial, but the related Debian bug implies that this is true for more recent systemd versions as well (didn't try in Bionic yet).

On Thu, Feb 22, 2018 at 9:16 AM, Scott Moser <email address hidden>
wrote:

> I dont think I really agree with this fix.
>
>
I forgot that we dropped local-fs.target for exactly what we needed:

After=systemd-remount-fs.service
RequiresMountFor=/var/lib/cloud

> Adding 'After=local-fs.target' essentially pushes cloud-init to have that
> same dependency, which it does not have. We don't really want cloud-init
> to have to wait for local-fs.target.
> For example see bug 1691489 (and related fallout bug 1717477).
>

I don't think it's so clear that it effectively pushes cloud-init-local out
to after local-fs.target
as, in general, cloud-init-local already runs *after* local-fs.target

Feb 22 15:48:47.065442 b2 systemd[1]: Started Set the console keyboard
layout.
Feb 22 15:48:47.066519 b2 systemd[1]: Reached target Local File Systems
(Pre).
Feb 22 15:48:47.066580 b2 systemd[1]: Reached target Local File Systems.
...
Feb 22 15:48:47.108237 b2 systemd[1]: systemd-tmpfiles-setup.service
...
Feb 22 15:48:47.153217 b2 systemd[1]: Starting Initial cloud-init job
(pre-networking)...

That's in bionic, without open-vm-tools.

I think we need some more information w.r.t open-vm-tools actual
requirement w.r.t running prior to cloud-init;
Assuming there is a need to run before cloud-init-local, then the unit
needs to be as precise as cloud-init
w.r.t what it actually requires w.r.t the filesystem (like the
RequiresMountFor).

IIUC, the bugs were related to blocking fsck and mount service to require
cloud-init.service, but that required local-fs.target
and a loop was created. Open-vm-tools is asking to run after
cloud-init-local, which is not emitted in any of mount entries
so I don't see a new loop coming.

>
> If the only reason for local-fs.target was actually PrivateTmp, then there
> is a bug in systemd.
>
> https://www.freedesktop.org/software/systemd/man/systemd.exec.html
> | Implicit Dependencies
> | Similar, units with PrivateTmp= enabled automatically get mount unit
> | dependencies for all mounts required to access /tmp and /var/tmp. They
> | will also gain an automatic After= dependency on systemd-tmpfiles-
> | setup.service(8).
>
> So there must have been a different read-only filesystem involved.
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1750780
>
> Title:
> Race with local file systems can make open-vm-tools fail to start
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/cloud-init/+bug/1750780/+subscriptions
>

There is a difference between cloud-init sometimes running after local-fs.target and being guaranteed to run after local-fs.target. The change here guarantees it.

For the moment, this isn't too bad, as cloud-init can't really affect local-fs.target because it isn't guaranteed to run before. But I suspect we will change that at some point, which would cause a dependency loop.

Could someone that can recreate this actually collect *all* output of
  systemctl status open-vm-tools
or even more ideally, modifying the job to 'strace -o -ff /run/open-vm-tools.'
and then collecting the /run/open-vm-tools files

Installed another Xenial and Bionic in vmware to take a deper look.
- Xenial (with backported open-vm-tools): affected
- Bionic (with the interim fix reverted): no hit in several retries, explanation below

Systemd fixed it (via our assumed implicit dependency).
In Bionic the PrivateTmp gives it a dependency on systemd-tmpfile-setup.service (seen in systemd analyze, there might be more but not on crit path).
This is configured by default to include /var/tmp in /usr/lib/tmpfiles.d/tmp.conf.

In regard to your thoughts about later on changing cloud-init ordering that won't help you, as the dependency is there (implicit or explicit doesn't matter).

For the xenial case where I reliably hit the issue instead of stracing I cut things short.
A service with the following exposes exactly the same error:
[Unit]
Description=foo
DefaultDependencies=no

[Service]
PrivateTmp=yes
ExecStart=/bin/true

[Install]
WantedBy=multi-user.target

So back on Xenial it is privateTmp + too early that breaks it.

Xenial vs Bionic critical-chain according to "systemd-analyze critical-chain open.vm-tools.service"

Xenial with fix:
open-vm-tools.service @3.482s
└─local-fs.target @3.460s
  └─local-fs-pre.target @3.460s
    └─systemd-remount-fs.service @3.442s +9ms
      └─system.slice @220ms
        └─-.slice @204m

Xenial without fix:
└─run-vmblock\x2dfuse.mount @6.076s +390ms
  └─sys-fs-fuse-connections.mount @5.510s +375ms
    └─systemd-modules-load.service @1.996s +75ms
      └─system.slice @1.984s
        └─-.slice @1.966s

Bionic
open-vm-tools.service @3.566s
└─systemd-tmpfiles-setup.service @3.421s +100ms
  └─systemd-journal-flush.service @3.054s +342ms
    └─systemd-journald.service @825ms +2.219s
      └─syslog.socket @808ms
        └─system.slice @621ms
          └─-.slice @613ms

To Summarize, we can:
- revert the fix for Bionic (or later) - just make it a sync when convenient down the road, it doesn't hurt for now as it is (almost) the same as the implicit dependency)
- add a xenials systemd bug task (probably too complex to fix as -upstream)
- until said systemd bug is fixed a backport of open-vm-tools needs this fix

I'Ll likely revert the Binonic change tmrw morning as we have discussed.
local-fs.target is actually >> the implicit dependency.

But that does not solve the Xenial issue outlined in the former comment.

I agree with reverting change in bionic, and that xenial still needs some fix.

I recreated your failure in xenial and agree with your change there.
I used this job as it actually tries to write to the private tmp.

If I change 'ExecStart' below to be just '/bin/true' like in your job, it does not fail (status says 'code=exited, status=0/SUCCESS). But the command below seems to never get exited (it produces no output).

So it seems to me that the 'Read only filesystem' error is not even from the service itself, but rather from systemd, and also dependent on the content in ExecStart.

$ cat /lib/systemd/system/my-ptmp-test.service
[Unit]
Description=foo
DefaultDependencies=no
[Service]
Type=oneshot
PrivateTmp=yes
ExecStart=/bin/sh -ec 'f=/tmp/my.txt; uptime > $f; echo ==; cat $f; echo ==; cat /proc/mounts'
[Install]
WantedBy=multi-user.target

Then we can see the same failure:

$ journalctl -o short-monotonic --no-pager | grep --context=2 my-ptmp-test
[ 7.715220] xenial-20180223-142555 systemd[1]: Created slice System Slice.
[ 7.718923] xenial-20180223-142555 systemd[1]: Created slice system-systemd\x2dfsck.slice.
[ 7.740250] xenial-20180223-142555 systemd[1]: my-ptmp-test.service: Failed to run 'start' task: Read-only file system
[ 7.749135] xenial-20180223-142555 systemd[1]: Failed to start foo.
[ 7.754114] xenial-20180223-142555 systemd[1]: my-ptmp-test.service: Unit entered failed state.
[ 7.760217] xenial-20180223-142555 systemd[1]: my-ptmp-test.service: Failed with result 'resources'.
[ 7.764170] xenial-20180223-142555 systemd[1]: Starting Load Kernel Modules...
[ 7.775558] xenial-20180223-142555 systemd[1]: Starting Journal Service...

$ systemctl status my-ptmp-test.service --no-pager --full
● my-ptmp-test.service - foo
   Loaded: loaded (/lib/systemd/system/my-ptmp-test.service; enabled; vendor preset: enabled)
   Active: failed (Result: resources)

Thanks Scott for your cross check.
I wonder why my former test failed on each of my tests without writing, but never the less your extended example is great for the systemd issue that remains.

Although all of this is still a race, for example with the job above on a Xenial container I could not trigger it in several retries (5/5 worked).
Doing the same in a Xenial KVM guest instead triggered it right away, but still not on every reboot (3/5 failed).

I hope that helps everybody trying to reproduce this.

With the former update in mind I retried Xenial/Bionic again.
All of it is racy (as we knew), but it never triggered for Bionic.

Xenial (19/33 fails)
Bionic (0/37 fails)

So for now we continue to assume that it is fixed there (by systemd) and revert our added dependency.

Note: as with the simple job in comment #12 and comment #14 this is Hipervisor agnostic.
You can even test the open-vm-tools service in KVM by removing the condition on vmware.

For open-vm-tools this issue will only exist with the planned backport of the newer version.
Since we will not ship the broken backport as we found it in pre-checks the correct state for open-vm-tools in xenial is invalid.

Note: When we do the Xenial backport of the new version of open-vm-tools (which we plan to do) this becomes an issue. In the same upload I intend to fix it right away, so it should never effectively exist in the field (keep invalid, but there might be a fix-released update to open-vm-tools here at some point).

This will only "become" an issue for Xenial/Artful with the backport.
But lets do it right for tracking - so I added/modified tasks for these releases which allows me to refer changes and changelog to here.

That way with the backport it will "be an issue" for the former releases, but also instantly be closed for them.

For SRU consideration, due to the newer systemd in >=Bionic it is not affected - so it is "invalid" there. But for SRU considerations this is ok, as the "most recent release has to be fixed" is covered, there won't be an upgrade regression as when going e.g. Xenial->Bionic.

In the queue for SRU review now - main bug 1741390

Hello ChristianEhrhardt, or anyone else affected,

Accepted open-vm-tools into xenial-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/open-vm-tools/2:10.2.0-3~ubuntu0.16.04.1 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation on how to enable and use -proposed.Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested and change the tag from verification-needed-xenial to verification-done-xenial. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed-xenial. In either case, without details of your testing we will not be able to proceed.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

Hello ChristianEhrhardt, or anyone else affected,

Accepted open-vm-tools into artful-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/open-vm-tools/2:10.2.0-3~ubuntu0.17.10.1 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation on how to enable and use -proposed.Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested and change the tag from verification-needed-artful to verification-done-artful. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed-artful. In either case, without details of your testing we will not be able to proceed.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

1. Upgrade from proposed - this is the same for all associated bugs, so I only documented details in bug 1741390

2. This bug in particular
Running a few restarts and checking
$ systemctl status -l open-vm-tools.service
This checks if the service rules avoid the issue on these systems with older systemd (older than Bionic where these extra constraints are not needed)

Artful: did not expose the issue in 5/5 retries
Xenial: did not expose the issue in 5/5 retries

Per above (and the extensive precheck on the content-equal ppa by VMWare) - setting to verified

This bug was fixed in the package open-vm-tools - 2:10.2.0-3~ubuntu0.16.04.1

---------------
open-vm-tools (2:10.2.0-3~ubuntu0.16.04.1) xenial; urgency=medium

  * backport Bionic open-vm-tools to Xenial (LP: #1741390)
    - d/control: B-D for dh-autoreconf and dh-systemd
    - d/rules: re-add autoreconf and systemd
    - d/control: B-D to debhelper version of xenial supporting compat 10
    - d/compat: compat level 10 is latest xenial supported level
    - d/rules: go back from override_dh_installsystemd to
      override_dh_systemd_enable and override_dh_systemd_start as needed on
      xenials debhelper version.
    - d/rules: drop --no-restart-after-upgrade which only exists in debhelper
      10, the version 9 behavior defaults to what we need.
    - debian/rules: dh_systemd_start in xenial has issues with the escaping of
      the run-vmblock\\x2dfuse.mount job, so drop this call
    - debian/open-vm-tools-desktop.postinst: add a fixed version of what
      dh_systemd_start would have added
    - d/open-vm-tools-desktop.prerm, d/open-vm-tools-desktop.postrm: add what
      dh_systemd_start would have added (as-is since those sections worked)
    - d/control: update maintainers
  * d/open-vm-tools.service: Add After=local-fs.target dependency ensuring
    filesystems are ready to fix a race on startup (LP: #1750780)

open-vm-tools (2:10.2.0-3ubuntu3) bionic; urgency=medium

  * Disable PrivateTmp for the open-vm-tools.service as it triggers issues
    when triggering processes that need tmp through VMOMI API (LP: #1758428)

open-vm-tools (2:10.2.0-3ubuntu2) bionic; urgency=medium

  * Revert change in d/open-vm-tools.service that added After=local-fs.target.
    It turned out that the systemd in bionic already implicitly fixes
    this issue (the change is still needed for backports) (LP: 1750780)

open-vm-tools (2:10.2.0-3ubuntu1) bionic; urgency=medium

  * d/open-vm-tools.service: Add After=local-fs.target dependency ensuring
    filesystems are ready to fix a race on startup (LP: #1750780)

open-vm-tools (2:10.2.0-3) unstable; urgency=medium

  * [47e50a1] Fix debhelper dep for backports
  * [34538a5] Make tools.conf useful.
    Thanks to Dariusz Gadomski (Closes: #889884)

open-vm-tools (2:10.2.0-2) unstable; urgency=medium

  * [249d54c] Fix wayland segfault.
    Adding a patch from Fedora to fix a wayland/gnome related segfault.
    Thanks to Oliver Kurth (Closes: #887755)

open-vm-tools (2:10.2.0-1) unstable; urgency=medium

  * [f0bf956] Add .travis.yml which was removed by gbp.
  * [892e2f6] Build with gtk3.
  * [03a655b] Check if debhelper handles \ in systemd units.
    Thanks to Oliver Kurth (Closes: #886191)
  * [5bf9301] Drop -dkms package.
    Thanks to Christian Ehrhardt (Closes: #884656)
  * [236cdba] Update upstream source from tag 'upstream/10.2.0'
    Update to upstream version '10.2.0'
    with Debian dir d5190e486b6beb65ee7ed31c0c23a789b8f60cab
    (Closes: #884496)
  * [692beff] snapshot changelog.
  * [45aa743] Add .travis.yml which was removed by gbp.
  * [aabeded] Fix dpkg --compare-versions call
  * [0697425] Better debhelper version parsing.
  * [390ec09] fix even more makefile bugs.
  * [6e5fa38] Refreshing...

The verification of the Stable Release Update for open-vm-tools has completed successfully and the package has now been released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regressions.

This bug was fixed in the package open-vm-tools - 2:10.2.0-3~ubuntu0.17.10.1

---------------
open-vm-tools (2:10.2.0-3~ubuntu0.17.10.1) artful; urgency=medium

  * backport Bionic open-vm-tools to Artful (LP: #1741390)
    - d/control: B-D for dh-autoreconf and dh-systemd
    - d/rules: re-add autoreconf and systemd
    - d/control: B-D to debhelper version of xenial supporting compat 10
    - d/compat: compat level 10 is latest xenial supported level
    - d/rules: go back from override_dh_installsystemd to
      override_dh_systemd_enable and override_dh_systemd_start as needed on
      xenials debhelper version.
    - d/rules: drop --no-restart-after-upgrade which only exists in debhelper
      10, the version 9 behavior defaults to what we need.
    - debian/rules: dh_systemd_start in xenial has issues with the escaping of
      the run-vmblock\\x2dfuse.mount job, so drop this call
    - debian/open-vm-tools-desktop.postinst: add a fixed version of what
      dh_systemd_start would have added
    - d/open-vm-tools-desktop.prerm, d/open-vm-tools-desktop.postrm: add what
      dh_systemd_start would have added (as-is since those sections worked)
    - d/control: update maintainers
  * d/open-vm-tools.service: Add After=local-fs.target dependency ensuring
    filesystems are ready to fix a race on startup (LP: #1750780)

open-vm-tools (2:10.2.0-3ubuntu3) bionic; urgency=medium

  * Disable PrivateTmp for the open-vm-tools.service as it triggers issues
    when triggering processes that need tmp through VMOMI API (LP: #1758428)

open-vm-tools (2:10.2.0-3ubuntu2) bionic; urgency=medium

  * Revert change in d/open-vm-tools.service that added After=local-fs.target.
    It turned out that the systemd in bionic already implicitly fixes
    this issue (the change is still needed for backports) (LP: 1750780)

open-vm-tools (2:10.2.0-3ubuntu1) bionic; urgency=medium

  * d/open-vm-tools.service: Add After=local-fs.target dependency ensuring
    filesystems are ready to fix a race on startup (LP: #1750780)

open-vm-tools (2:10.2.0-3) unstable; urgency=medium

  * [47e50a1] Fix debhelper dep for backports
  * [34538a5] Make tools.conf useful.
    Thanks to Dariusz Gadomski (Closes: #889884)

open-vm-tools (2:10.2.0-2) unstable; urgency=medium

  * [249d54c] Fix wayland segfault.
    Adding a patch from Fedora to fix a wayland/gnome related segfault.
    Thanks to Oliver Kurth (Closes: #887755)

open-vm-tools (2:10.2.0-1) unstable; urgency=medium

  * [f0bf956] Add .travis.yml which was removed by gbp.
  * [892e2f6] Build with gtk3.
  * [03a655b] Check if debhelper handles \ in systemd units.
    Thanks to Oliver Kurth (Closes: #886191)
  * [5bf9301] Drop -dkms package.
    Thanks to Christian Ehrhardt (Closes: #884656)
  * [236cdba] Update upstream source from tag 'upstream/10.2.0'
    Update to upstream version '10.2.0'
    with Debian dir d5190e486b6beb65ee7ed31c0c23a789b8f60cab
    (Closes: #884496)
  * [692beff] snapshot changelog.
  * [45aa743] Add .travis.yml which was removed by gbp.
  * [aabeded] Fix dpkg --compare-versions call
  * [0697425] Better debhelper version parsing.
  * [390ec09] fix even more makefile bugs.
  * [6e5fa38] Refreshing...

So, is there anything requested to be done with Xenial's systemd in this bug?

No, unless you were afraid that what ticked open-vm-tools into having issues here being a wider more general issue. But then given that 16.04 is used widely for quite some time I think we can assume it is a corner case only.

incomplete on the systemd task is ok.

Tracked in Github Issues as https://github.com/canonical/cloud-init/issues/3122