Ubuntu
ubuntu-advantage-tools package

Unexpected error(s) occurred is logged in syslog

Bug #2002613 reported by Jaromir Obr on 2023-01-12

This bug affects 2 people

Affects		Status	Importance	Assigned to	Milestone
	ubuntu-advantage-tools (Ubuntu)	Incomplete	Undecided	Unassigned
	update-manager (Ubuntu)	Confirmed	Undecided	Unassigned

Bug Description

I noticed an error in syslog
----------------------------------
Jan 12 07:57:18 rzbox update-notifier.desktop[380935]: Unexpected error(s) occurred.
Jan 12 07:57:18 rzbox update-notifier.desktop[380935]: For more details, see the log: /var/log/ubuntu-advantage.log
Jan 12 07:57:18 rzbox update-notifier.desktop[380935]: To file a bug run: ubuntu-bug ubuntu-advantage-tools
Jan 12 07:57:18 rzbox update-notifier.desktop[348424]: Traceback (most recent call last):
Jan 12 07:57:18 rzbox update-notifier.desktop[348424]: File "/usr/lib/python3/dist-packages/UpdateManager/UpdateManager.py", line 241, in start_available
Jan 12 07:57:18 rzbox update-notifier.desktop[348424]: self.refresh_cache()
Jan 12 07:57:18 rzbox update-notifier.desktop[348424]: File "/usr/lib/python3/dist-packages/UpdateManager/UpdateManager.py", line 449, in refresh_cache
Jan 12 07:57:18 rzbox update-notifier.desktop[348424]: self._get_ua_security_status()
Jan 12 07:57:18 rzbox update-notifier.desktop[348424]: File "/usr/lib/python3/dist-packages/UpdateManager/UpdateManager.py", line 285, in _get_ua_security_status
Jan 12 07:57:18 rzbox update-notifier.desktop[348424]: s = json.load(p.stdout)
Jan 12 07:57:18 rzbox update-notifier.desktop[348424]: File "/usr/lib/python3.10/json/__init__.py", line 293, in load
Jan 12 07:57:18 rzbox update-notifier.desktop[348424]: return loads(fp.read(),
Jan 12 07:57:18 rzbox update-notifier.desktop[348424]: File "/usr/lib/python3.10/json/__init__.py", line 346, in loads
Jan 12 07:57:18 rzbox update-notifier.desktop[348424]: return _default_decoder.decode(s)
Jan 12 07:57:18 rzbox update-notifier.desktop[348424]: File "/usr/lib/python3.10/json/decoder.py", line 337, in decode
Jan 12 07:57:18 rzbox update-notifier.desktop[348424]: obj, end = self.raw_decode(s, idx=_w(s, 0).end())
Jan 12 07:57:18 rzbox update-notifier.desktop[348424]: File "/usr/lib/python3.10/json/decoder.py", line 355, in raw_decode
Jan 12 07:57:18 rzbox update-notifier.desktop[348424]: raise JSONDecodeError("Expecting value", s, err.value) from None
Jan 12 07:57:18 rzbox update-notifier.desktop[348424]: json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
Jan 12 07:57:18 rzbox systemd[1]: Starting Process error reports when automatic reporting is enabled...
Jan 12 07:57:18 rzbox systemd[1]: Started crash report submission.
Jan 12 07:57:18 rzbox whoopsie[381183]: [07:57:18] Using lock path: /var/lock/whoopsie/lock
Jan 12 07:57:18 rzbox systemd[1]: whoopsie.service: Deactivated successfully.
Jan 12 07:57:18 rzbox whoopsie-upload-all[381182]: INFO:root:Collecting info for /var/crash/_usr_bin_update-manager.1000.crash...
Jan 12 07:57:23 rzbox whoopsie-upload-all[381182]: WARNING: hook failed for processing /var/crash/_usr_bin_update-manager.1000.crash:
Jan 12 07:57:23 rzbox whoopsie-upload-all[381182]: INFO:root:Marking /var/crash/_usr_bin_update-manager.1000.crash for whoopsie upload
Jan 12 07:57:23 rzbox whoopsie-upload-all[381182]: INFO:root:/var/crash/_usr_share_skypeforlinux_skypeforlinux.1000.crash already marked for upload, skipping
Jan 12 07:57:23 rzbox whoopsie-upload-all[381182]: INFO:root:Waiting for whoopsie to upload reports (timeout: 20 s)
Jan 12 07:57:23 rzbox whoopsie-upload-all[381182]: INFO:root: missing (remaining: 20 s): /var/crash/_usr_bin_update-manager.1000.uploaded
Jan 12 07:57:23 rzbox systemd[1]: Started crash report submission.
Jan 12 07:57:23 rzbox whoopsie[383250]: [07:57:23] Using lock path: /var/lock/whoopsie/lock
Jan 12 07:57:23 rzbox whoopsie[383250]: [07:57:23] Parsing /var/crash/_usr_bin_update-manager.1000.crash.
Jan 12 07:57:23 rzbox whoopsie[383250]: [07:57:23] Uploading /var/crash/_usr_bin_update-manager.1000.crash.
Jan 12 07:57:24 rzbox whoopsie[383250]: [07:57:24] Sent; server replied with: No error
Jan 12 07:57:24 rzbox whoopsie[383250]: [07:57:24] Response code: 200
Jan 12 07:57:24 rzbox whoopsie[383250]: [07:57:24] Reported OOPS ID 5db82aca-9246-11ed-b711-fa163ef35206
Jan 12 07:57:24 rzbox systemd[1]: whoopsie.service: Deactivated successfully.
Jan 12 07:57:33 rzbox whoopsie-upload-all[381182]: INFO:root:All reports uploaded successfully
Jan 12 07:57:33 rzbox systemd[1]: apport-autoreport.service: Deactivated successfully.
Jan 12 07:57:33 rzbox systemd[1]: Finished Process error reports when automatic reporting is enabled.
Jan 12 07:57:33 rzbox systemd[1]: apport-autoreport.service: Consumed 3.783s CPU time.

ProblemType: Bug
DistroRelease: Ubuntu 22.10
Package: ubuntu-advantage-tools 27.12~22.10.1
Uname: Linux 6.1.4-060104-generic x86_64
ApportVersion: 2.23.1-0ubuntu3
Architecture: amd64
CasperMD5CheckResult: pass
CurrentDesktop: ubuntu:GNOME
Date: Thu Jan 12 08:08:15 2023
InstallationDate: Installed on 2022-05-23 (233 days ago)
InstallationMedia: Ubuntu 22.04 LTS "Jammy Jellyfish" - Release amd64 (20220419)
RebootRequiredPkgs: Error: path contained symlinks.
SourcePackage: ubuntu-advantage-tools
UpgradeStatus: Upgraded to kinetic on 2023-01-04 (7 days ago)
cloud-id.txt-error: Invalid command specified 'cloud-id'.
jobs-status.json: {"update_messaging": {"last_run": "2023-01-11T10:35:00.075554+00:00", "next_run": "2023-01-11T16:35:00.075554+00:00"}, "update_status": {"last_run": "2023-01-11T10:35:00.075554+00:00", "next_run": "2023-01-11T22:35:00.075554+00:00"}, "metering": {"last_run": "2023-01-11T10:35:00.075554+00:00", "next_run": "2023-01-11T14:35:00.075554+00:00"}}
livepatch-status.txt-error: Failed running command '/snap/bin/canonical-livepatch status' [exit(1)]. Message: error executing status: livepatchd error: The platform Ubuntu 22.10 is not supported. exiting.

Tags:

Revision history for this message

Jaromir Obr (jaromir-obr) wrote on 2023-01-12:

Dependencies.txt Edit (2.4 KiB, text/plain; charset="utf-8")
ProcCpuinfoMinimal.txt Edit (1.5 KiB, text/plain; charset="utf-8")
ProcEnviron.txt Edit (310 bytes, text/plain; charset="utf-8")
ua-status.json.txt Edit (2.6 KiB, text/plain; charset="utf-8")
uaclient.conf.txt Edit (610 bytes, text/plain; charset="utf-8")
ubuntu-advantage-timer.log.txt Edit (28.1 KiB, text/plain; charset="utf-8")
ubuntu-advantage.log.txt Edit (334.3 KiB, text/plain; charset="utf-8")

Renan Rodrigo (renanrodrigo) on 2023-01-17

information type:

Private → Public

Apport retracing service (apport) on 2023-01-17

tags:

removed: need-amd64-retrace

Revision history for this message

Grant Orndorff (orndorffgrant) wrote on 2023-01-18:

Hello jaromir-obr,

Thank you for taking the time to report this bug! It looks like the command `ua security-status --format=json` is failing, but it isn't evident why from the logs attached.

Can you please run in your terminal `sudo ua security-status --format=json` and report what the output is? Also please upload the contents of /var/log/ubuntu-advantage.log after running the command.

Thanks again,
Grant

Revision history for this message

Jaromir Obr (jaromir-obr) wrote on 2023-01-18:

security-status.json Edit (1.8 KiB, application/json)

Revision history for this message

Jaromir Obr (jaromir-obr) wrote on 2023-01-18:

ubuntu-advantage.log Edit (346.1 KiB, text/plain)

Revision history for this message

Grant Orndorff (orndorffgrant) wrote on 2023-01-19:

Thank you jaromir-obr!

Unfortunately, since the command succeeded when run manually, the logs and output don't provide much information. And I've tried to reproduce this without success. Since we don't have a reproducer or enough details about the error, I'll mark this incomplete for ubuntu-advantage-tools.

At the very least, though, I think update-manager should handle this kind of error more gracefully. I'll move this bug to update-manager to represent that.

Specifically, for update-manager, if something goes wrong early enough in the `ua security-status --format=json` command, then the output won't be json. To cover this, we'll need a try/except around the json.loads call.

Longer term, we should probably replace this `ua security-status --format=json` command with using the more recent pro client python api: https://github.com/canonical/ubuntu-advantage-client/blob/main/docs/references/api.md#upropackagesupdatesv1

Changed in ubuntu-advantage-tools (Ubuntu):
status:	New → Incomplete

Revision history for this message

Gyurkan Mehmed (gm93) wrote on 2023-03-27:

Hi, I am also getting error related to this when using update-manager:
ua: error: unrecognized arguments: security-status --format=json
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/UpdateManager/backend/InstallBackendAptdaemon.py", line 448, in _on_finished
    self._action_done(action,
  File "/usr/lib/python3/dist-packages/UpdateManager/backend/__init__.py", line 365, in _action_done
    self.window_main.start_available()
  File "/usr/lib/python3/dist-packages/UpdateManager/UpdateManager.py", line 241, in start_available
    self.refresh_cache()
  File "/usr/lib/python3/dist-packages/UpdateManager/UpdateManager.py", line 449, in refresh_cache
    self._get_ua_security_status()
  File "/usr/lib/python3/dist-packages/UpdateManager/UpdateManager.py", line 285, in _get_ua_security_status
    s = json.load(p.stdout)
  File "/usr/lib/python3.10/json/__init__.py", line 293, in load
    return loads(fp.read(),
  File "/usr/lib/python3.10/json/__init__.py", line 346, in loads
    return _default_decoder.decode(s)
  File "/usr/lib/python3.10/json/decoder.py", line 337, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
  File "/usr/lib/python3.10/json/decoder.py", line 355, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

Revision history for this message

Gyurkan Mehmed (gm93) wrote on 2023-03-27 (last edit on 2023-03-27):

Hmm I found out that when using update-manager - ua is ran as non-root user and that causes the issue as it tries to use status.json which can be used when running ua as root only. Any ideas how to resolve the issue?

Revision history for this message

Launchpad Janitor (janitor) wrote on 2023-03-27:

Status changed to 'Confirmed' because the bug affects multiple users.

Changed in update-manager (Ubuntu):
status:	New → Confirmed

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Bug attachments

Add attachment

Remote bug watches

Bug watches keep track of this bug in other bug trackers.

Ubuntuubuntu-advantage-tools package

Unexpected error(s) occurred is logged in syslog

Bug Description

Other bug subscribers

Bug attachments

Remote bug watches

Ubuntu
ubuntu-advantage-tools package