[Impact]
The /var/lib/ubuntu-advantage/notices.json file may get corrupted, as it is written by the CLI applications on specific situations (for example: contract change, reboot required), but it's also modified by the background services executed by the tool.
The mitigation here is done through three changes:
- writing each notice to its own file, so different notices are not written to the same file
- do not use JSON, but save plain text files instead
- make sure writes are atomic (write to tmp, move to the correct directory)
[Test Case]
On a VM running u-a-t 27.13.6:
- attach a token
- create an invalid notices.json, with the content below
```
[["", "FIPS support requires system reboot to complete configuration."]] ["", "Operation in progress: timer metering job"]]]
```
- run `pro status`, see that it fails
- upgrade to version >= 27.14
- run `pro status`, see that a) it runs and b) the reboot message is kept at best effort
- verify the /var/run/ubuntu-advantage/notices directory exists and has the reboot notice
- verify this reboot notice has no json content
- verify that /var/lib/ubuntu-advantage/notices.json does not exist anymore.
[Regression Potential]
Notices are now defined in the code, and just represented in files in /var/lib or /var/run.
The changes in the code will ignore any unknown notice file - which means that if we create some valid file with the wrong name, this notice will not be shown and users won't see it. We think this is acceptable, as it is better than having the exception, and we re-check for the existence of those notices in several flows of execution.
If we made some mistake in the transition to the one-file to the many-files, all notices may be lost.
[Discussion]
It is very hard to simulate this bug, as this is a very well timed race condition. Therefore, we are simulating it by corrupting the JSON ourselves for the test and verification.
We are arguing that invalid notices won't show in this new model, because our notices are now code-controlled, and invalid notices will not be taken into consideration. They are also unlikely to happen now because files are atomically written. The only case is not showing a valid notice, as discussed above.
[Original Description]
```log
2022-08-25 14:08:16,982 - util.py:(696) [DEBUG]: Failed running command '/snap/bin/canonical-livepatch status' [exit(1)]. Message: cannot change profile for the next exec call: No such file or directory
Retrying 2 more times.
2022-08-25 14:08:17,528 - util.py:(696) [DEBUG]: Failed running command '/snap/bin/canonical-livepatch status' [exit(1)]. Message: cannot change profile for the next exec call: No such file or directory
Retrying 1 more times.
2022-08-25 14:08:18,567 - livepatch.py:(285) [DEBUG]: Livepatch not enabled. Failed running command '/snap/bin/canonical-livepatch status' [exit(1)]. Message: cannot change profile for the next exec call: No such file or directory
2022-08-25 14:08:18,567 - util.py:(437) [DEBUG]: Reading file: /var/lib/ubuntu-advantage/notices.json
2022-08-25 14:08:18,568 - util.py:(725) [DEBUG]: Writing file: /var/lib/ubuntu-advantage/notices.json
2022-08-25 14:08:18,569 - util.py:(437) [DEBUG]: Reading file: /var/lib/ubuntu-advantage/notices.json
2022-08-25 14:08:18,569 - util.py:(725) [DEBUG]: Writing file: /var/lib/ubuntu-advantage/notices.json
2022-08-25 14:08:18,569 - util.py:(437) [DEBUG]: Reading file: /var/lib/ubuntu-advantage/notices.json
2022-08-25 14:08:18,569 - util.py:(725) [DEBUG]: Writing file: /var/lib/ubuntu-advantage/notices.json
2022-08-25 14:08:18,570 - util.py:(437) [DEBUG]: Reading file: /var/lib/ubuntu-advantage/notices.json
2022-08-25 14:08:18,570 - cli.py:(1841) [ERROR]: Unhandled exception, please file a bug
Traceback (most recent call last):
File "/usr/lib/python3/dist-packages/uaclient/cli.py", line 1791, in wrapper
return func(*args, **kwargs)
File "/usr/lib/python3/dist-packages/uaclient/cli.py", line 1897, in main
return args.action(args, cfg=cfg)
File "/usr/lib/python3/dist-packages/uaclient/cli.py", line 1613, in action_status
cfg, simulate_with_token=token, show_beta=show_beta
File "/usr/lib/python3/dist-packages/uaclient/actions.py", line 118, in status
status = ua_status.status(cfg=cfg, show_beta=show_beta)
File "/usr/lib/python3/dist-packages/uaclient/status.py", line 339, in status
response = _attached_status(cfg)
File "/usr/lib/python3/dist-packages/uaclient/status.py", line 201, in _attached_status
_attached_service_status(ent, inapplicable_resources)
File "/usr/lib/python3/dist-packages/uaclient/status.py", line 115, in _attached_service_status
ent_status, details = ent.user_facing_status()
File "/usr/lib/python3/dist-packages/uaclient/entitlements/base.py", line 917, in user_facing_status
applicability, details = self.applicability_status()
File "/usr/lib/python3/dist-packages/uaclient/entitlements/base.py", line 562, in applicability_status
for error_message, functor, expected_result in self.static_affordances:
File "/usr/lib/python3/dist-packages/uaclient/entitlements/livepatch.py", line 124, in static_affordances
fips_ent.application_status()[0] == ApplicationStatus.ENABLED
File "/usr/lib/python3/dist-packages/uaclient/entitlements/fips.py", line 337, in application_status
self.cfg.remove_notice("", messages.FIPS_DISABLE_REBOOT_REQUIRED)
File "/usr/lib/python3/dist-packages/uaclient/config.py", line 357, in remove_notice
for notice_label, notice_descr in cached_notices:
ValueError: not enough values to unpack (expected 2, got 1)
2022-08-25 14:08:18,901 - cli.py:(1878) [DEBUG]: Executed with sys.argv: ['/usr/bin/ua', 'attach', '<REDACTED>']
2022-08-25 14:08:18,901 - cli.py:(1826) [ERROR]: This machine is already attached to 'zendesk'
To use a different subscription first run: sudo ua detach.
2022-08-25 14:08:19,247 - cli.py:(1878) [DEBUG]: Executed with sys.argv: ['/usr/bin/ua', 'status']
2
```
```
2022-08-25 14:08:19,423 - cli.py:(1841) [ERROR]: Unhandled exception, please file a bug
Traceback (most recent call last):
File "/usr/lib/python3/dist-packages/uaclient/cli.py", line 1791, in wrapper
return func(*args, **kwargs)
File "/usr/lib/python3/dist-packages/uaclient/cli.py", line 1897, in main
return args.action(args, cfg=cfg)
File "/usr/lib/python3/dist-packages/uaclient/cli.py", line 1604, in action_status
cfg.add_notice("", messages.NOTICE_REFRESH_CONTRACT_WARNING)
File "/usr/lib/python3/dist-packages/uaclient/config.py", line 343, in add_notice
if notice not in notices:
TypeError: 'in <string>' requires string as left operand, not list
2022-08-25 14:43:13,241 - cli.py:(1878) [DEBUG]: Executed with sys.argv: ['/usr/bin/ua', 'status']
2
```
The json is:
```sh
~# cat /var/lib/ubuntu-advantage/notices.json
[["", "A change has been detected in your contract.\nPlease run `sudo ua refresh`."]] ["", "Operation in progress: timer metering job"]]
```
Notice there's an unmatched "]".
ProblemType: Bug
DistroRelease: Ubuntu 16.04
Package: ubuntu-advantage-tools 27.9~16.04.1
ProcVersionSignature: Ubuntu 4.4.0-1134.148-aws 4.4.262
Uname: Linux 4.4.0-1134-aws x86_64
NonfreeKernelModules: lkp_Ubuntu_4_4_0_1134_148_aws_89 lkp_Ubuntu_4_4_0_1134_148_aws_87 lkp_Ubuntu_4_4_0_1134_148_aws_86 lkp_Ubuntu_4_4_0_1134_148_aws_85
ApportVersion: 2.20.1-0ubuntu2.30+esm3
Architecture: amd64
Date: Fri Aug 26 08:15:46 2022
Ec2AMI: ami-08d0f633da7d3c35d
Ec2AMIManifest: (unknown)
Ec2AvailabilityZone: eu-west-1c
Ec2InstanceType: m6i.2xlarge
Ec2Kernel: unavailable
Ec2Ramdisk: unavailable
ProcEnviron:
TERM=xterm-256color
SHELL=/bin/bash
PATH=(custom, no user)
LANG=en_US.UTF-8
LC_CTYPE=en_US.UTF-8
SourcePackage: ubuntu-advantage-tools
UpgradeStatus: No upgrade log present (probably fresh install)
Hello liangyun-gong,
Thank you for reporting this bug!
We suspect this happened because of an unlikely collision between the background metering job running and using the cli at the same time.
For now you can safely `rm /var/lib/
Please let us know if this happens again.
We have plans to restructure our notice storage to avoid collisions in the future and we won't close this bug until that is resolved.