Bug 55230 - UCR cache is broken since Python 3 migration
UCR cache is broken since Python 3 migration
Status: RESOLVED MOVED
Product: UCS
Classification: Unclassified
Component: UCR
UCS 5.0
Other Linux
: P5 normal (vote)
: ---
Assigned To: UCS maintainers
UCS maintainers
https://git.knut.univention.de/univen...
: python3-migration
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2022-09-28 09:52 CEST by Florian Best
Modified: 2022-10-05 13:33 CEST (History)
2 users (show)

See Also:
What kind of report is it?: Development Internal
What type of bug is this?: ---
Who will be affected by this bug?: ---
How will those affected feel about the bug?: ---
User Pain:
Enterprise Customer affected?:
School Customer affected?:
ISV affected?:
Waiting Support:
Flags outvoted (downgraded) after PO Review:
Ticket number:
Bug group (optional):
Max CVSS v3 score:


Attachments
Atomic cache update et al. (2.39 KB, patch)
2022-10-05 13:31 CEST, Philipp Hahn
Details | Diff
Atomic cache update et al. (23.20 KB, patch)
2022-10-05 13:33 CEST, Philipp Hahn
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Florian Best univentionstaff 2022-09-28 09:52:42 CEST
```
28.09.22 00:00:14.807  DEBUG_INIT
28.09.22 00:00:14.915  LISTENER    ( WARN    ) : Notifier/LDAP server is master090.autotest090.local:7389
28.09.22 00:00:14.915  LDAP        ( PROCESS ) : connecting to ldap://master090.autotest090.local:7389
28.09.22 00:00:34.533  LISTENER    ( ERROR   ) : import of filename=/usr/lib/univention-directory-listener/system/cups-printers.py failed
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/univention/config_registry/handler.py", line 707, in load
    version = self._get_cache_version(cache_file)
  File "/usr/lib/python3/dist-packages/univention/config_registry/handler.py", line 681, in _get_cache_version
    match = ConfigHandlers.VERSION_RE.match(line)
TypeError: cannot use a string pattern on a bytes-like object

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/univention-directory-listener/system/cups-printers.py", line 48, in <module>
    ucr_handlers.load()
  File "/usr/lib/python3/dist-packages/univention/config_registry/handler.py", line 722, in load
    self.update()
  File "/usr/lib/python3/dist-packages/univention/config_registry/handler.py", line 924, in update
    for section in self._parse_rfc822_file(info):
  File "/usr/lib/python3/dist-packages/univention/config_registry/handler.py", line 699, in _parse_rfc822_file
    with open(fname, 'r', encoding='utf-8') as fd:
FileNotFoundError: [Errno 2] No such file or directory: '/etc/univention/templates/info/univention-system-setup-boot.info'
```

The cache file is opened in bytes mode for unpickling, but prior to that the first line is read to parse a version.
Comment 2 Philipp Hahn univentionstaff 2022-10-05 13:31:10 CEST
Created attachment 10992 [details]
Atomic cache update et al.

(In reply to Florian Best from comment #0)
> Traceback (most recent call last):
>   File "/usr/lib/python3/dist-packages/univention/config_registry/handler.py", line 707, in load
>     version = self._get_cache_version(cache_file)
>   File "/usr/lib/python3/dist-packages/univention/config_registry/handler.py", line 681, in _get_cache_version
>     match = ConfigHandlers.VERSION_RE.match(line)
> TypeError: cannot use a string pattern on a bytes-like object

While UCR code is actually wrong and mixed bytes and str — which you MR fixes — this is not the real problem here: this TypeError is handled by an `except (Exception, pickle.UnpicklingError):` in python/univention/config_registry/handler.py:721

While in that part `update()` is called when then a 2nd exception occurs:

> During handling of the above exception, another exception occurred:
> 
> Traceback (most recent call last):
>   File "/usr/lib/univention-directory-listener/system/cups-printers.py", line 48, in <module>
>     ucr_handlers.load()
>   File "/usr/lib/python3/dist-packages/univention/config_registry/handler.py", line 722, in load
>     self.update()
>   File "/usr/lib/python3/dist-packages/univention/config_registry/handler.py", line 924, in update
>     for section in self._parse_rfc822_file(info):
>   File "/usr/lib/python3/dist-packages/univention/config_registry/handler.py", line 699, in _parse_rfc822_file
>     with open(fname, 'r', encoding='utf-8') as fd:
> FileNotFoundError: [Errno 2] No such file or directory: '/etc/univention/templates/info/univention-system-setup-boot.info'

This looks like a concurrency problem and/or someone has fiddled with that path as `os.walk()` is used to walk the directory "/etc/univention/templates/info/" by univention.config_registry.misc.directory_files(), which just checked that it is a file using `os.path.isfile()` before `open(…)` is used to actually open it.

So actually this looks like the UDL module for CUPS was called just as someone updated the system and USS-boot.info got purged (or move aside by dpkg during an update: it's a conffile which is handled special in Debian). During that the cache became invalid and UDL triggered the path to fix the cache by updating it.

The correct solution would be to make univention.config_registry.handler.ConfigHandlers._save_cache() atomic, e.g. build a new cache in a sibling-file and only move it after at the successful end.
Comment 3 Philipp Hahn univentionstaff 2022-10-05 13:33:23 CEST
Created attachment 10993 [details]
Atomic cache update et al.