High CPU usage of /usr/bin/landscape-package-reporter
Hello,
Our team met another issue in landscape-client and we could not find a reasonable explanation.
The issue is:
/usr/bin/
Our question is, if we change --urgent-
Thanks a lot!
Question information
- Language:
- English Edit question
- Status:
- Solved
- Assignee:
- Jan-Yaeger Dhillon Edit question
- Last query:
- Last reply:
|
Revision history for this message
|
#1 |
Can you check if that happens for a long period of time? If so, for how long? landscape-
|
Revision history for this message
|
#2 |
Hi Alex,
Thank you for the quick response. It takes landscape-
Here is the details:
1. urgent-
2. landscape-
3. When it gets triggered, apt-get update finished quickly in seconds, but landscape-
4. When CPU is high, we can see a big chunk of data payload in broker.log, like this:
{'accepted-types': '\xaew\
'client-api': '3.7',
'messages': [{'api': '3.3', .......
Here is the settings in our client.conf file:
exchange_interval = 900
registration_key = **
log_level = debug
include_
url = https:/
computer_title = ABCD
apt_update_interval = 900
account_name = standalone
script_users = ALL
ping_url = http://
access_group =**
ssl_public_key = /etc/landscape/
urgent_
package_
ping_interval = 60
|
Revision history for this message
|
#3 |
Your client.conf contains a "log_level = debug" setting, which causes landscape-client to log a lot of debug information, including the content of messages being exchanged with the server. That causes increased cpu and IO usage.
Please try commenting/removing that line in the config, and restart landscape client (sudo service landscape-client restart).
|
Revision history for this message
|
#4 |
Thanks a lot! Our QA will have another try when he has time and I will post result here afterwards.
|
Revision history for this message
|
#5 |
Hello,
It looks like removing the log level did not help too much. It reduced running time from 30 seconds to 25 seconds, but still too long. Is there any other possibility can cause this? Thanks!
|
Revision history for this message
|
#6 |
Here are some more information we found may help you advise:
If we keep both /etc/apt/
If we keep only files in /etc/apt/
Looking into sources.list file, we found that the slowness seems to be caused by fetching xenial/universe and xenial/multiverse repos. These 2 repos have large number of packages.
However, apt-get update is faster because apt-get update does not check into xenial/universe and xenial/multiverse every time, it caches for a while.
Do you know why landscape-
Is there a way to prevent the process checking repo so often or only update the repo we want?
Thanks!
|
Revision history for this message
|
#7 |
This question was expired because it remained in the 'Open' state without activity for the last 15 days.
|
Revision history for this message
|
#8 |
Canonical Team, any additional help here? Right now, its checking against every package in the public repos in sources.list.
What we'd like is a lightweight ping every 60 seconds, and only run an update if something is available to update. Is there a way to set this up with our registration parameters? Using package profiles?
|
Revision history for this message
|
#9 |
Still happens with Ubuntu 20.04, here using around 100 seconds of CPU time (i7-4700MQ CPU) every half hour (with default desktop installation with no additional repo and basic landscape deployement). Uses 100% of one CPU over 100 seconds. Some noticeable effect on user interface, and fans triggered.
|
Revision history for this message
|
#10 |
Hello Canonical, this issue still happens on newer version of Ubuntu as well. Can you please look into this?
|
Revision history for this message
|
#11 |
Hi Vincent. Can you provide us with the version of landscape-client you are running, the version of Ubuntu it is installed on, and your client.conf file?
|
Revision history for this message
|
#12 |
I confirm that this problem exists on the latest landscape client version 23.08+git6296-
We are self-hosting landscape server on-premise
I include the package-
2024-06-13 09:30:11,344 INFO [MainThread] Downloaded hash=>id database from https:/
2024-06-13 09:30:11,545 WARNING [MainThread] Removing cached hash=>id database /var/lib/
2024-06-13 09:30:16,817 INFO [MainThread] Queuing request for package hash => id translation on 500 hash(es).
2024-06-13 09:31:00,538 INFO [MainThread] Queuing message with changes in known packages: 854 installed, 83936 available, 3 available upgrades, 0 locked, 1 autoremovable, 19900 security, 0 not installed, 0 not available, 0 not available upgrades, 0 not locked, 0 not autoremovable, 0 not security.
2024-06-13 09:31:25,918 INFO [MainThread] Downloaded hash=>id database from https:/
2024-06-13 09:31:26,041 INFO [MainThread] Received 500 package hash => id translations, 0 hashes are unknown.
2024-06-13 09:31:31,149 INFO [MainThread] Queuing request for package hash => id translation on 500 hash(es).
2024-06-13 09:32:14,605 INFO [MainThread] Queuing message with changes in known packages: 56 installed, 482 available, 1 available upgrades, 0 locked, 0 autoremovable, 152 security, 0 not installed, 0 not available, 0 not available upgrades, 0 not locked, 0 not autoremovable, 0 not security.
2024-06-13 09:32:34,573 INFO [MainThread] Received 500 package hash => id translations, 0 hashes are unknown.
2024-06-13 09:32:39,776 INFO [MainThread] Queuing request for package hash => id translation on 500 hash(es).
2024-06-13 09:33:23,438 INFO [MainThread] Queuing message with changes in known packages: 62 installed, 475 available, 0 available upgrades, 0 locked, 1 autoremovable, 163 security, 0 not installed, 0 not available, 0 not available upgrades, 0 not locked, 0 not autoremovable, 0 not security.
2024-06-13 09:33:43,987 INFO [MainThread] Received 500 package hash => id translations, 0 hashes are unknown.
2024-06-13 09:33:49,160 INFO [MainThread] Queuing request for package hash => id translation on 500 hash(es).
2024-06-13 09:34:32,798 INFO [MainThread] Queuing message with changes in known packages: 50 installed, 476 available, 0 available upgrades, 0 locked, 1 autoremovable, 165 security, 0 not installed, 0 not available, 0 not available upgrades, 0 not locked, 0 not autoremovable, 0 not security.
2024-06-13 09:34:51,776 INFO [MainThread] Received 500 package hash => id translations, 0 hashes are unknown.
2024-06-13 09:34:56,889 INFO [MainThread] Queuing request for package hash => id translation on 500 hash(es).
2024-06-13 09:35:40,638 INFO [MainThread] Queuing message with changes in known packages: 53 installed, 476 available, 0 available upgrades, 0 locked, 0 autoremovable, 169 security, 0 not installed, 0 not available, 0 not available upgrades, 0 not locked, 0 not autoremovable, 0 not security.
2024-06-13 09:35:59,769 INFO [MainThread] Received 500 package hash => id translations, 0 hashes are unknown.
2024-06-13 09:36:04,961 INFO [MainThread] Queuing request for package hash => id translation on 500 hash(es).
2024-06-13 09:36:49,275 INFO [MainThread] Queuing message with changes in known packages: 65 installed, 477 available, 0 available upgrades, 0 locked, 2 autoremovable, 148 security, 0 not installed, 0 not available, 0 not available upgrades, 0 not locked, 0 not autoremovable, 0 not security.
2024-06-13 09:37:08,282 INFO [MainThread] Received 500 package hash => id translations, 0 hashes are unknown.
2024-06-13 09:37:13,397 INFO [MainThread] Queuing request for package hash => id translation on 500 hash(es).
2024-06-13 09:37:57,404 INFO [MainThread] Queuing message with changes in known packages: 63 installed, 475 available, 0 available upgrades, 0 locked, 0 autoremovable, 149 security, 0 not installed, 0 not available, 0 not available upgrades, 0 not locked, 0 not autoremovable, 0 not security.
2024-06-13 09:38:16,174 INFO [MainThread] Received 500 package hash => id translations, 0 hashes are unknown.
2024-06-13 09:38:21,333 INFO [MainThread] Queuing request for package hash => id translation on 500 hash(es).
2024-06-13 09:39:06,183 INFO [MainThread] Queuing message with changes in known packages: 74 installed, 478 available, 0 available upgrades, 0 locked, 1 autoremovable, 158 security, 0 not installed, 0 not available, 0 not available upgrades, 0 not locked, 0 not autoremovable, 0 not security.
2024-06-13 09:39:20,684 INFO [MainThread] Received 500 package hash => id translations, 0 hashes are unknown.
2024-06-13 09:39:25,870 INFO [MainThread] Queuing request for package hash => id translation on 500 hash(es).
2024-06-13 09:40:10,679 INFO [MainThread] Queuing message with changes in known packages: 58 installed, 479 available, 0 available upgrades, 0 locked, 1 autoremovable, 153 security, 0 not installed, 0 not available, 0 not available upgrades, 0 not locked, 0 not autoremovable, 0 not security.
2024-06-13 09:40:32,264 INFO [MainThread] Received 500 package hash => id translations, 0 hashes are unknown.
2024-06-13 09:40:37,431 INFO [MainThread] Queuing request for package hash => id translation on 500 hash(es).
2024-06-13 09:41:22,691 INFO [MainThread] Queuing message with changes in known packages: 62 installed, 484 available, 0 available upgrades, 0 locked, 0 autoremovable, 174 security, 0 not installed, 0 not available, 0 not available upgrades, 0 not locked, 0 not autoremovable, 0 not security.
2024-06-13 09:41:40,815 INFO [MainThread] Received 500 package hash => id translations, 0 hashes are unknown.
2024-06-13 09:41:45,984 INFO [MainThread] Queuing request for package hash => id translation on 500 hash(es).
2024-06-13 09:42:31,659 INFO [MainThread] Queuing message with changes in known packages: 59 installed, 487 available, 0 available upgrades, 0 locked, 0 autoremovable, 169 security, 0 not installed, 0 not available, 0 not available upgrades, 0 not locked, 0 not autoremovable, 0 not security.
2024-06-13 09:42:48,596 INFO [MainThread] Received 500 package hash => id translations, 0 hashes are unknown.
2024-06-13 09:42:53,821 INFO [MainThread] Queuing request for package hash => id translation on 500 hash(es).
|
Revision history for this message
|
#13 |
This is the the timing config we currently have in client.conf file
apt_update_interval = 36000
package_
ping_interval = 60
exchange_interval = 900
urgent_
snap_monitor_
|
Revision history for this message
|
#14 |
Having this problem too in Ubuntu server 24.04.1 LTS.
|
Revision history for this message
|
#15 |
There is a cron job that runs the hash-id-databases script. It runs weekly. Make sure it is running. This should help speed things up
|
Revision history for this message
|
#17 |
In my case it was the package_
|
Revision history for this message
|
#18 |
This seems to be a problem on both servers on which I am running landscape. How is it this bug is still ongoing after 9 years, or does it come and go over the years?
|
Revision history for this message
|
#19 |
24.04 I'm having this same issue.
/etc/landscape/
[client]
log_level = info
url = https:/
ping_url = http://
data_path = /var/lib/
computer_title = zarko-ThinkPad-
account_name = xxx
registration_key = xxx
package_
|
Revision history for this message
|
#20 |
I've also noticed this high CPU usage (on a laptop as part of an organisation that uses landscape, so my main concern is battery consumption) and have done a bit of investigation on the client side.
As far as I can tell, each time it shows "Received 500 package hash => id translations" in the log, it will invoke an instance of `/usr/bin/
The vast majority of CPU time in `landscape-
This command line basically simulates the use of the `.origins` property as used by each invocation of `landscape-
```
$ time python3 -c 'import apt; print(len([origin for package in apt.cache.Cache() if package.name == package.shortname for version in package.versions for origin in [*version.origins, *version.origins, *version.
544719
real 0m52.465s
user 0m33.427s
sys 0m19.029s
```
Digging deeper, the reason this takes so long is because each time "python-apt" constructs an `Origin` object, it will call `find_index`, which involves walking through all package index files:
https:/
https:/
https:/
If I stub out the call to `find_index`, the command above only takes 1.3 seconds rather than 52.
I imagine the most efficient solution would be to get `python-apt` to cache the index objects per package index file instead of walking through the filesystem every time. Otherwise there could be some smaller gains (maybe cutting time to a third) within landscape-client by storing `package.origins` in a variable instead of invoking the property multiple times.
It probably also helps not having a large number of package index files (/var/lib/
|
Revision history for this message
|
#21 |
Hi Max, thanks for your thoughts and helping us to resolve this issue. I've been doing some testing with your suggested change and I'd like to share my findings.
Checkout my branch in landscape-client:
cd landscape-client
git fetch --all
git checkout lndeng-
You will see I made the change you suggested in landscape/
I have been using our unit testing to run some benchmarking in landscape/
def test_detect_
"""
Benchmark test for package change detection performance.
"""
import statistics
import time
import base64
hash_ids = {
): i
for i in range(NUM_PACKAGES)
}
stats = []
for _ in range(NUM_
start = time.perf_counter()
elapsed = time.perf_counter() - start
and doing 10 trials on my branch and main with:
for i in $(seq 1 10); do python3 -m twisted.trial landscape.
You can find my observations here: https:/
I wasn't able to get a significant performance increase as a result. Can you try out my testing to see if this is what you had in mind?
Thanks
|
Revision history for this message
|
#22 |
Hi Jan-Yaeger,
Thanks for looking at this.
This might be due to my unfamiliarity with Launchpad, but I don't seem to be able to find your branch. It's not in the main "landscape-client" repository (https:/
I've added your test case manually, but it doesn't seem to trigger the issue, since the benchmark records about 0.2 ms, similar to in your spreadsheet.
I noticed your test has a bug though: it looks like the string that gets base64-encoded is meant to be interpolated, but it's missing the `f` prefix, so you end up with `len(hash_ids) == 1`. Fixing this still doesn't trigger the issue however.
I'm not familiar enough with landscape-client to reproduce it properly within a test case. After a bit of experimentation I can see that the test setup only has 1 "Packages" file (eg, "/tmp/tmpcxbyi5
$ python3 -c 'import apt; [print(version) for package in apt.cache.Cache() if package.name == package.shortname for version in package.versions]' | wc -l
106235
As I alluded to in my previous comment, I think the issue is dependent on the number of packages in the apt repository and the number of Packages files. I manually added some logging into "/usr/lib/
|
Revision history for this message
|
#23 |
Hi again Max,
I've been going through Landscape Client to reproduce the issue and capture it in a test. Some of this legacy code can be quite nebulous honestly, but I think I may have gotten it.
git clone --single-branch --branch lndeng-
python3 -m twisted.trial landscape.
I've been using this test in landscape/
def benchmark(self):
"""
Benchmark test for performance.
"""
import time
NUM_PKGS = 10000
start = time.perf_counter()
for i in range(NUM_PKGS):
name = f"test-{i}"
)
Testing with:
python3 -m twisted.trial landscape.
You can find the updated results here: https:/
It does seem to be creating the specified amount of packages now, and we definitely see the slowdown. However, I'm not sure if the change I made ended up making a difference. Based off my understanding, this would involve a much bigger change than what I've done.
Please let me know your thoughts and if you are able to see my branch.
|
Revision history for this message
|
#24 |
Hi again,
I think it has more to do with the number of package index files, since it's possible to have an arbitrary number of those (eg, about 37 on the Ubuntu systems I have access to) whereas the total number of packages will probably be similar across systems (eg, about 100k). The time to iterate over the packages is basically multiplied by the number of package index files, so 100k packages across 40 indexes will take 20 times as long as 100k packages across 2 indexes.
I don't think your latest benchmark test triggers the relevant code, since it doesn't seem to call `detect_
I've managed to put together this updated version of your original test (to be placed within "test_reporter.py", `PackageReporte
def test_detect_
"""
Benchmark test for performance.
"""
import time
NUM_PKGS = 10000
NUM_LISTS = 400
for i in range(NUM_PKGS):
name = f"test-{i}"
)
repos_dir = self.makeDir()
for i in range(NUM_LISTS):
with open(packages_file, "wb") as packages:
start = time.perf_counter()
I've used an exaggerated number of package index files (400 instead of 37), since the test setup takes long enough for only 10k packages, let alone 100k (looking at it through strace, adding each package to the test involves reading/writing the existing package list, so the setup time will be quadratic WRT the number of packages).
Normally this test reports 73 seconds for `detect_
You do seem to be correct however in that the change in landscape-client doesn't actually help that much, since it appears that the `.origins` property is usually only accessed once per package (accessing it a second/third time only occurs based on some *-backports/
I guess then this can only feasibly be solved by having "python-apt" cache the result of `find_index` against the `SourceList` object (`pkg._
|
Revision history for this message
|
#25 |
> Most of the remaining 22 seconds seems to be after the package iteration loop; haven't looked into what it's doing there.
Just to add to this, these 22 seconds are spent in `AptFacade.
|
Revision history for this message
|
#26 |
Hi again Max, thanks again for your help and thoughts. I've been doing some refactoring of the code to avoid calling package.origins and I think I may have some promising results. Someone on my team pointed out that we only need the archives to check if the given package version is in the backport or security archives, which we can construct directly without calling package.origins. You can find my branch here: https:/
I've included the git diffs and the benchmarking results below. As you can see, this does seem to reflect the speedup you were seeing by manually stubbing out the call to find_index in the apt package. And if we look at the function calls, find_index is only called in the unmodified code. Package reporter keeps working as expected as well. Are you able to try this new testing out and let me know if this is more what you had in mind?
Modified:
```
diff --git a/landscape/
index b784317b..36b697ab 100644
--- a/landscape/
+++ b/landscape/
@@ -654,6 +654,22 @@ class PackageReporter
return False
def _compute_
+ import cProfile
+ import pstats
+
+ profile = cProfile.Profile()
+ profile.enable()
+ result = self.compute_
+ profile.disable()
+
+ output_path = "/tmp/lib/
+ with open(output_path, "a") as fp:
+ stats = pstats.
+ stats.strip_
+
+ return result
+
+ def compute_
"""Analyse changes in the universe of known packages.
This method will verify if there are packages that:
@@ -705,14 +721,11 @@ class PackageReporter
# support pinning, but we don't yet. In the mean time, we
# ignore backports, so that packages don't get automatically
# upgraded to the backports version.
- backport_origins = [
- origin
- for origin in package.origins
- if origin.archive == backports_archive
- ]
- if backport_origins and (
- len(backport_
- ):
+ archives = [a[0].archive for a in package.
+ backports_origins = all(
+ archive == backports_archive for archive in archives
+ )
+ if backports_origins:
# Ignore the version if it's only in the official
# backports archive. If it's somewhere else as well,
# e.g. a PPA, we assume it was added manually and the
@@ -736,10 +749,11 @@ class PackageReporter
# Is this package present in the security pocket?
- origin
- for origin in package.origins
- if origin.archive == security_archive
+ archive
+ for archive in archives
+ if archive == security_archive
)
+
if security_origins:
```
Results: https:/
Unchanged (with benchmark):
```
diff --git a/landscape/
index b784317b..faf64aa0 100644
--- a/landscape/
+++ b/landscape/
@@ -654,6 +654,22 @@ class PackageReporter
return False
def _compute_
+ import cProfile
+ import pstats
+
+ profile = cProfile.Profile()
+ profile.enable()
+ result = self.compute_
+ profile.disable()
+
+ output_path = "/tmp/lib/
+ with open(output_path, "a") as fp:
+ stats = pstats.
+ stats.strip_
+
+ return result
+
+ def compute_
"""Analyse changes in the universe of known packages.
This method will verify if there are packages that:
```
Results: https:/
|
Revision history for this message
|
#27 |
Hi,
Those changes seem to solve the performance issue, thanks! I don't fully understand the logic in the old or new code so can't comment on the correctness of it, but it seems to avoid calling the problematic code as you mentioned.
|
Revision history for this message
|
#28 |
That's great to hear! I'll keep testing to ensure everything is still working as intended. For reference here is the updated spreadsheet: https:/
Hopefully we can get this fix out soon! Keep an eye on our repo (https:/
|
Revision history for this message
|
#29 |
Just an update that I've opened a PR for this issue :)
|
Revision history for this message
|
#30 |
The PR has been approved and merged!
https:/
