Problems with package reporting
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
Landscape Client |
Fix Released
|
Medium
|
Thomas Herve |
Bug Description
I have been experiencing problems with package reporting lately. Basically the server says there are updates available for a certain computer, but when you click on the number of updates in the packages page, nothing is listed. Likewise, if you click on security updates, nothing is listed, even though the packages page even has an USN for the computer.
I also saw problems with "request all upgrades". An activity would come back with things like "Remove package unknown", signaling some serious problem with the hash-id mapping of packages.
What I have debugged so far is this:
- the update_
- if that file does not exist, the package changer refuses to run (and I have seen this in the logs). That by itself means the changer could be locked up for up to 6h (the default apt_update_interval value):
if not self.update_
return succeed(None)
==> /var/log/
2013-02-27 13:48:59,008 WARNING [MainThread] The package-reporter hasn't run yet, exiting.
Still, this shouldn't block the reporter from requesting and reporting hashes, right, and indeed doesn't seem to (extra logging changes applied locally):
2013-02-27 15:07:35,077 INFO [MainThread] Queuing request for package hash => id translation on 108 hash(es).
2013-02-27 15:08:35,835 INFO [MainThread] apt_update_
2013-02-27 15:08:35,835 INFO [MainThread] force_apt_
2013-02-27 15:08:35,837 INFO [MainThread] _apt_sources_
2013-02-27 15:08:35,837 INFO [MainThread] _apt_update_
2013-02-27 15:08:35,837 INFO [MainThread] os.path.
2013-02-27 15:08:35,837 INFO [MainThread] '/usr/lib/
2013-02-27 15:08:35,847 INFO [MainThread] Received 108 package hash => id translations, 0 hashes are unknown.
Still, this machine in particular is reporting 3 upgrades available, but when you click on the number nothing is listed. It will only get "in sync" if run_apt_update() runs. Basically, I can call landscape-
# sudo -u landscape landscape-
2013-02-27 15:37:30,500 INFO [MainThread] apt_update_
2013-02-27 15:37:30,501 INFO [MainThread] force_apt_
2013-02-27 15:37:30,502 INFO [MainThread] _apt_sources_
2013-02-27 15:37:30,502 INFO [MainThread] _apt_update_
2013-02-27 15:37:30,503 INFO [MainThread] os.path.
2013-02-27 15:37:49,611 INFO [MainThread] Queuing request for package hash => id translation on 4 hash(es).
2013-02-27 15:37:52,218 INFO [MainThread] Queuing message with changes in known packages: 17 installed, 596 available, 8 available upgrades, 0 locked, 0 not installed, 0 not available, 0 not available upgrades, 0 not locked.
So maybe what it before this forced run was just the state of the hash-id-database file, not even considering what the system's previous apt-get update run brought in (taken from the timestamp of /var/lib/
Related branches
- Christopher Armstrong (community): Approve
- Chris Glass (community): Approve
-
Diff: 97 lines (+36/-6)2 files modifiedlandscape/package/reporter.py (+10/-5)
landscape/package/tests/test_reporter.py (+26/-1)
tags: | removed: kanban |
Changed in landscape-client: | |
importance: | Undecided → Medium |
Changed in landscape-client: | |
assignee: | nobody → Thomas Herve (therve) |
status: | New → In Progress |
Changed in landscape-client: | |
status: | In Progress → Fix Committed |
Changed in landscape-client: | |
status: | Fix Committed → Fix Released |
Here is some logging with a full session. I started with a clean /var/lib/ landscape/ client and registered the client.
At the end of this, the UI was showing, for this computer:
Available: 43311
Installed: 429
Upgrades: 3 (link)
Held: -
If you click on the 3 upgrades link, it takes you to an empty listing.
Here are the logs, in chronological order:
tail -F /var/log/ landscape/ {broker, package- changer, package- reporter} .log landscape/ broker. log <== twisted. internet. reactor- 1] Sent 636 bytes and received 178 bytes in 0.09s. 7c25-11e2- bbc0-525400ba0f dc). provisioned- machine +register-cloud-vm /inst-025. virtual- maas.com/ message- system. twisted. internet. reactor- 1] Sent 873 bytes and received 180 bytes in 0.27s. landscape/ package- changer. log' for reading: No such file or directory landscape/ package- reporter. log' for reading: No such file or directory
==> /var/log/
2013-02-27 16:17:32,498 INFO [PoolThread-
2013-02-27 16:17:32,498 INFO [MainThread] Switching to normal exchange mode.
2013-02-27 16:17:32,499 INFO [MainThread] Server UUID changed (old=None, new=f166d22c-
2013-02-27 16:17:32,500 INFO [MainThread] Accepted types changed: +test +register +register-
2013-02-27 16:17:32,517 INFO [MainThread] Queueing message to register with account 'standalone' and tags grizzly,cloud with a password.
2013-02-27 16:17:32,518 INFO [MainThread] Starting message exchange with https:/
2013-02-27 16:17:32,522 INFO [MainThread] Message exchange completed in 0.12s.
2013-02-27 16:17:32,795 INFO [PoolThread-
2013-02-27 16:17:32,797 INFO [MainThread] Using new secure-id ending with SWbi0UGoFO for account standalone.
2013-02-27 16:17:32,799 INFO [MainThread] Message exchange completed in 0.28s.
tail: cannot open `/var/log/
tail: cannot open `/var/log/
==> /var/log/ landscape/ broker. log <== /inst-025. virtual- maas.com/ message- system. twisted. internet. reactor- 2] Sent 636 bytes and received 801 bytes in 0.14s. process- info +update- manager- info +reboot-required +change- packages- result +temperature +apt-preferences +keystone-token +users +reboot- required- info +cpu-usage +package- reporter- result +hardware-info +load-average +packages +unknown- package- hashes +add-packages +free-space +action-info +resynchronize +processor-info +swift-device-info +network-device +distribution-info test -register -register- provisioned- machine -register-cloud-vm landscape/ package- reporter. log' has become accessible
2013-02-27 16:18:02,801 INFO [MainThread] Ping indicates message available. Scheduling an urgent exchange.
2013-02-27 16:18:32,799 INFO [MainThread] Starting urgent message exchange with https:/
2013-02-27 16:18:32,801 INFO [MainThread] Ping indicates message available. Scheduling an urgent exchange.
2013-02-27 16:18:32,939 INFO [PoolThread-
2013-02-27 16:18:32,940 INFO [MainThread] Switching to normal exchange mode.
2013-02-27 16:18:32,941 INFO [MainThread] Accepted types changed: +computer-info +operation-result +ceph-usage +memory-info +mount-info +text-message +network-activity +mount-activity +custom-graph +active-
2013-02-27 16:18:32,954 INFO [MainThread] Message exchange completed in 0.15s.
tail: `/var/log/
==> /var/log/la...