Old broker lockfile blocks landscape-client starts

Interestingly, I had the same problem on another machine, but with a different lockfile:

FileExistsError: [Errno 17] File exists: '1516' -> b'/var/lib/landscape/client/sockets/monitor.sock.lock'

So I think there is some situation, possibly an upgrade from bionic to focal, which is causing lost lockfiles which then block future starts.

And again, on a third machine. This seems to be occurring on Focal, but
it's not just an upgrade issue.

Mark

Here's a new traceback that may be related to the same underlying issue. We should harden all the affected codepaths.

2020-04-02 09:49:49,780 ERROR [MainThread] Can't keep landscape-manager running. Exiting.
2020-04-02 09:49:49,781 INFO [MainThread] Stopping client...
Traceback (most recent call last):
  File "/usr/bin/landscape-manager", line 8, in <module>
    run(sys.argv)
  File "/usr/lib/python3/dist-packages/landscape/client/manager/service.py", line 62, in run
    run_landscape_service(ManagerConfiguration, ManagerService, args)
  File "/usr/lib/python3/dist-packages/landscape/client/service.py", line 115, in run_landscape_service
    startApplication(application, False)
  File "/usr/lib/python3/dist-packages/twisted/application/app.py", line 690, in startApplication
    service.IService(application).startService()
  File "/usr/lib/python3/dist-packages/twisted/application/service.py", line 288, in startService
    service.startService()
  File "/usr/lib/python3/dist-packages/landscape/client/manager/service.py", line 41, in startService
    self.publisher.start()
  File "/usr/lib/python3/dist-packages/landscape/client/amp.py", line 45, in start
    self._port = self._reactor.listen_unix(socket_path, factory)
  File "/usr/lib/python3/dist-packages/landscape/lib/reactor.py", line 228, in listen_unix
    return self._reactor.listenUNIX(socket, factory, wantPID=True)
  File "/usr/lib/python3/dist-packages/twisted/internet/posixbase.py", line 397, in listenUNIX
    p.startListening()
  File "/usr/lib/python3/dist-packages/twisted/internet/unix.py", line 373, in startListening
    raise error.CannotListenError(None, self.port,
twisted.internet.error.CannotListenError: Couldn't listen on any:b'/var/lib/landscape/client/sockets/manager.sock': Cannot acquire lock.
2020-04-02 09:49:49,894 INFO [MainThread] Monitor stopped with config /etc/landscape/client.conf
2020-04-02 09:49:49,896 INFO [MainThread] 0 of 0 expected load average snapshot events (0.00%) occurred in the last 2.03s.
2020-04-02 09:49:49,896 INFO [MainThread] 0 of 0 expected memory/swap snapshot events (0.00%) occurred in the last 2.03s.
2020-04-02 09:49:49,897 INFO [MainThread] 0 of 0 expected mount info snapshot events (0.00%) occurred in the last 2.03s.
2020-04-02 09:49:49,897 INFO [MainThread] 0 of 0 expected temperature snapshot events (0.00%) occurred in the last 2.03s.
2020-04-02 09:49:49,897 INFO [MainThread] 0 of 0 expected CPU usage snapshot events (0.00%) occurred in the last 2.02s.
2020-04-02 09:49:49,897 INFO [MainThread] 0 of 0 expected Swift device usage snapshot events (0.00%) occurred in the last 2.02s.
2020-04-02 09:49:49,897 INFO [MainThread] 0 of 0 expected Ceph usage snapshot events (0.00%) occurred in the last 2.02s.
2020-04-02 09:49:50,787 INFO [MainThread] Broker stopped with config /etc/landscape/client.conf

In this latter case, I wonder if the issue is permissions:

$ sudo ls /var/lib/landscape/client/sockets/ -la
total 8
drwxr-x--- 2 landscape root 4096 Apr 2 09:49 .
drwxr-xr-x 7 landscape root 4096 Apr 2 09:49 ..
srw-rw-rw- 1 landscape landscape 0 Apr 2 09:49 broker.sock
lrwxrwxrwx 1 landscape landscape 5 Apr 2 09:49 broker.sock.lock -> 14491
srw-rw-rw- 1 root root 0 Mar 29 11:42 manager.sock
lrwxrwxrwx 1 root root 4 Mar 29 11:42 manager.sock.lock -> 2073
srw-rw-rw- 1 landscape landscape 0 Apr 2 09:49 monitor.sock
lrwxrwxrwx 1 landscape landscape 5 Apr 2 09:49 monitor.sock.lock -> 14492

This matches this python-twisted issue, where lockfiles fail when PIDs are recycled.
https://twistedmatrix.com/trac/ticket/9738#ticket

Working on a similar workaround, but with extra checks, as landscape-manager run as root and the PermissionError won't surface in this case.

Sponsored in Focal.

Thanks for your contribution Simon.

- Eric

This bug was fixed in the package landscape-client - 19.12-0ubuntu4

---------------
landscape-client (19.12-0ubuntu4) focal; urgency=medium

  * d/p/0002-lp1870087-stale-locks.patch:
    Clean stale twisted lock files (LP: #1870087)

 -- Simon Poirier <email address hidden> Tue, 14 Apr 2020 11:07:41 -0400

Thanks all, I will keep an eye on my systems to see if the issue goes
away. It was triggered regularly on Focal machines so should be quite
easy to spot if it comes back :).

The update to landscape-client 19.12-0ubuntu4 failed on several of my
servers. I apply updates via Landscape, so it might be a divide-by-zero
issue with landscape failing to update itself cleanly. I did a
widespread push of updates and saw several servers fail. When I ssh to
the actual servers and resume updates with 'dpkg --configure -a' it is
always landscape-client which is first to run. Under those
circumstances, landscape-client finishes its configuration, so I think
it is failing when the update is done by itself :)

Hi folks, I think you need to reopen this bug. I just saw the issue again on several Focal machines. It's definitely not fix-released.

It's probably the second issue Simon is working on (namely that manually apt-get updating the client works but the client updating *itself* when left to its own devices still doesn't). I'll move back to in progress and there's indeed a branch proposed ATM.

I'll be happy to sponsor the second patch[0] as soon as focal transition from devel to stable is completed.

[0] - d/p/0003-service-killmode.patch

- Eric

I left a comment in the MP as follows:
"Don't quilt files under debian/. It should always be patchless."

I'll fix it manually and will upload in groovy today, so that I can move with focal hopefully tomorrow.

- Eric

Uploaded in groovy (see groovy.debdiff)

Once it reaches -releases, I'll go ahead with Focal.

This bug was fixed in the package landscape-client - 19.12-0ubuntu5

---------------
landscape-client (19.12-0ubuntu5) groovy; urgency=medium

  * d/landscape-client.service (LP: #1870087)
    - Set KillMode on service to avoid killing dpkg
      through self-upgrade.

 -- Simon Poirier <email address hidden> Mon, 27 Apr 2020 16:13:02 +0000

Sponsored in Focal:
https://launchpad.net/ubuntu/focal/+queue?queue_state=1&queue_text=landscape-client

Now waiting in the upload queue. I already pinged sil2100 for SRU approval.

- Eric

Hello Mark, or anyone else affected,

Accepted landscape-client into focal-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/landscape-client/19.12-0ubuntu4.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, what testing has been performed on the package and change the tag from verification-needed-focal to verification-done-focal. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed-focal. 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 for helping!

N.B. The updated package will be released to -updates after the bug(s) fixed by this package have been verified and the package has been in -proposed for a minimum of 7 days.

I've verified the upgrade path on focal by triggering an update through Landscape of packages landscape-client and landscape-common from 19.12-0ubuntu4 to 19.12-0ubuntu4.1

Upgrade went through, successfully leaving configuration subprocesses to finish cleanly:

Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)
||/ Name Version Architecture
+++-================-================-============
ii landscape-client 19.12-0ubuntu4.1 amd64
ii landscape-common 19.12-0ubuntu4.1 amd64

This bug was fixed in the package landscape-client - 19.12-0ubuntu4.1

---------------
landscape-client (19.12-0ubuntu4.1) focal; urgency=medium

  * d/landscape-client.service (LP: #1870087)
    - Set KillMode on service to avoid killing dpkg
      through self-upgrade.

 -- Simon Poirier <email address hidden> Mon, 27 Apr 2020 17:34:53 +0000

The verification of the Stable Release Update for landscape-client has completed successfully and the package is now being 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.

Hi folks, I am still seeing this issue intermittently in Ubuntu 20.04.

$ sudo apt-cache policy landscape-client
landscape-client:
  Installed: 19.12-0ubuntu4.1
  Candidate: 19.12-0ubuntu4.1
  Version table:
 *** 19.12-0ubuntu4.1 500
        500 http://archive.ubuntu.com/ubuntu focal-updates/main amd64 Packages
        100 /var/lib/dpkg/status
     19.12-0ubuntu4 500
        500 http://archive.ubuntu.com/ubuntu focal/main amd64 Packages
$ sudo ls -l /var/lib/landscape/client/sockets/
total 0
srw-rw-rw- 1 landscape landscape 0 Jun 12 12:32 broker.sock
lrwxrwxrwx 1 landscape landscape 4 Jun 12 12:32 broker.sock.lock -> 1451
srw-rw-rw- 1 root root 0 Jun 19 19:25 manager.sock
lrwxrwxrwx 1 root root 4 Jun 19 19:25 manager.sock.lock -> 1451
srw-rw-rw- 1 landscape landscape 0 Jun 19 19:25 monitor.sock
lrwxrwxrwx 1 landscape landscape 4 Jun 19 19:25 monitor.sock.lock -> 1450

Removing broker.sock and broker.sock.lock allowed the client to start up cleanly.

We definitely have not addressed this issue correctly or completely.

Hi Mark and anyone affected. Just to clarify the remaining part of the issue:

From the various test scenarios which I have tried, the initial issue of the client failing to restart in the presence of stale lock files and sockets appears to be resolved. That is, lock files pointing to dead or recycled PIDs should not prevent client starting if the client is in fact not running. This can be verified by checking processes matching PIDs are not landscape:

  ls -l /var/lib/landscape/client/sockets/*.sock.lock
  readlink -v /var/lib/landscape/client/sockets/*.sock.lock | xargs ps

However, there is an issue of processes not cleaning their lock/sock at exit. This issue affects all currently supported releases (as far as 16.04) and should be addressed in an upcoming patch.

Just to say thank you for progressing this :)

Hi Simon,

I see that you have set me as a reviewer for a new bug fix for that corner case bug.
I'll gladly review the patch most likely tomorrow, with first uploading the active devel release and then follow with the SRU.

The SRU team, recently added some modification to the actual SRU template
[Test] -> [TEST PLAN]
[Regression potential] -> [WHERE PROBLEMS COULD OCCUR]

Official documentation:
https://wiki.ubuntu.com/StableReleaseUpdates#SRU_Bug_Template

Could you please revisit the current template above, first to make sure it is still aligned with your most recent fix/findings and/or secondly to update the obsolete section name convention ?

I'll take care of the rest.

Thanks for your contributions.

- Eric

Fix in Hirsute.

landscape-client (19.12-0ubuntu8) hirsute; urgency=medium

  * d/p/0003-clean-publisher-shutdown.patch:
    Let publisher services shutdown cleanly (LP: #1870087)

 -- Simon Poirier <EMAIL> Mon, 01 Mar 2021 21:00:40 -0500

Hello Mark, or anyone else affected,

Accepted landscape-client into groovy-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/landscape-client/19.12-0ubuntu5.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, what testing has been performed on the package and change the tag from verification-needed-groovy to verification-done-groovy. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed-groovy. 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 for helping!

N.B. The updated package will be released to -updates after the bug(s) fixed by this package have been verified and the package has been in -proposed for a minimum of 7 days.

Hello Mark, or anyone else affected,

Accepted landscape-client into focal-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/landscape-client/19.12-0ubuntu4.2 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, what testing has been performed on the package and change the tag from verification-needed-focal to verification-done-focal. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed-focal. 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 for helping!

N.B. The updated package will be released to -updates after the bug(s) fixed by this package have been verified and the package has been in -proposed for a minimum of 7 days.

I verified the fixes for groovy-proposed and focal-proposed packages versions 19.12-0ubuntu5.1 and 19.12-0ubuntu4.2

I followed the test case without any issue.
Additionally, I also tried a few scenarios for terminating processes, which now all terminate cleanly if stopped with SIGTERM, whether directly or indirectly (through systemd).

This bug was fixed in the package landscape-client - 19.12-0ubuntu5.1

---------------
landscape-client (19.12-0ubuntu5.1) groovy; urgency=medium

  * d/p/0003-clean-publisher-shutdown.patch:
    Let publisher services shutdown cleanly (LP: #1870087)

 -- Simon Poirier <email address hidden> Thu, 27 Aug 2020 17:44:25 -0400

This bug was fixed in the package landscape-client - 19.12-0ubuntu4.2

---------------
landscape-client (19.12-0ubuntu4.2) focal; urgency=medium

  * d/p/0003-clean-publisher-shutdown.patch:
    Let publisher services shutdown cleanly (LP: #1870087)

 -- Simon Poirier <email address hidden> Thu, 27 Aug 2020 17:44:25 -0400

It seems the issue still persists for 19.12-0ubuntu4.3 and this version seems to be the latest for focal-updates [1].

Oct 02 08:34:59 rzlxswpsql02 audit[1331]: SYSCALL arch=c000003e syscall=257 success=yes exit=6 a0=ffffff9c a1=7faa7de1cf10 a2=80000 a3=0 items=1 ppid=1014 pid=1331 auid=4294967295 uid=110 gid=115 euid=110 suid=1
10 fsuid=110 egid=115 sgid=115 fsgid=115 tty=(none) ses=4294967295 comm="landscape-broke" exe="/usr/bin/python3.8" key="landscape_changes"
Oct 02 08:34:59 rzlxswpsql02 audit: PATH item=0 name="/etc/landscape/client.conf" inode=15784 dev=08:01 mode=0100600 ouid=110 ogid=0 rdev=00:00 nametype=NORMAL cap_fp=0 cap_fi=0 cap_fe=0 cap_fver=0 cap_frootid=0
Oct 02 08:34:59 rzlxswpsql02 audit[1339]: SYSCALL arch=c000003e syscall=257 success=yes exit=6 a0=ffffff9c a1=7fc12da20fd0 a2=80000 a3=0 items=1 ppid=1014 pid=1339 auid=4294967295 uid=110 gid=115 euid=110 suid=1
10 fsuid=110 egid=115 sgid=115 fsgid=115 tty=(none) ses=4294967295 comm="landscape-broke" exe="/usr/bin/python3.8" key="landscape_changes"
Oct 02 08:34:59 rzlxswpsql02 audit: PATH item=0 name="/etc/landscape/client.conf" inode=15784 dev=08:01 mode=0100600 ouid=110 ogid=0 rdev=00:00 nametype=NORMAL cap_fp=0 cap_fi=0 cap_fe=0 cap_fver=0 cap_frootid=0
Oct 02 08:35:00 rzlxswpsql02 landscape-client[1014]: Traceback (most recent call last):
Oct 02 08:35:00 rzlxswpsql02 landscape-client[1014]: File "/usr/lib/python3/dist-packages/twisted/python/lockfile.py", line 160, in lock
Oct 02 08:35:00 rzlxswpsql02 landscape-client[1014]: symlink(str(os.getpid()), self.name)
Oct 02 08:35:00 rzlxswpsql02 landscape-client[1014]: FileExistsError: [Errno 17] File exists: '1323' -> b'/var/lib/landscape/client/sockets/broker.sock.lock'
Oct 02 08:35:00 rzlxswpsql02 landscape-client[1014]: During handling of the above exception, another exception occurred:
Oct 02 08:35:00 rzlxswpsql02 landscape-client[1014]: Traceback (most recent call last):
Oct 02 08:35:00 rzlxswpsql02 landscape-client[1014]: File "/usr/bin/landscape-broker", line 8, in <module>
Oct 02 08:35:00 rzlxswpsql02 landscape-client[1014]: run(sys.argv)
Oct 02 08:35:00 rzlxswpsql02 landscape-client[1014]: File "/usr/lib/python3/dist-packages/landscape/client/broker/service.py", line 94, in run
Oct 02 08:35:00 rzlxswpsql02 landscape-client[1014]: run_landscape_service(BrokerConfiguration, BrokerService, args)
Oct 02 08:35:00 rzlxswpsql02 landscape-client[1014]: File "/usr/lib/python3/dist-packages/landscape/client/service.py", line 115, in run_landscape_service
Oct 02 08:35:00 rzlxswpsql02 landscape-client[1014]: startApplication(application, False)
Oct 02 08:35:00 rzlxswpsql02 landscape-client[1014]: File "/usr/lib/python3/dist-packages/twisted/application/app.py", line 690, in startApplication
Oct 02 08:35:00 rzlxswpsql02 landscape-client[1014]: service.IService(application).startService()
Oct 02 08:35:00 rzlxswpsql02 landscape-client[1014]: File "/usr/lib/python3/dist-packages/twisted/application/service.py", line 288, in startService
Oct 02 08:35:00 rzlxswpsql02 landscape-client[1014]: service.startService()
Oct 02 08:35:00 rzlxswpsql02 landscape-client[1014]: File "/usr/lib/python3/dist-pac...