Bug 49056 - TypeError in admin-diary client-lib causes crash of univention-upgrade in docker
TypeError in admin-diary client-lib causes crash of univention-upgrade in docker
Status: CLOSED FIXED
Product: UCS
Classification: Unclassified
Component: Admin Diary
UCS 4.4
Other Linux
: P5 normal (vote)
: UCS 4.4-0-errata
Assigned To: Arvid Requate
Felix Botner
:
: 49518 (view as bug list)
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2019-03-21 17:50 CET by Daniel Tröder
Modified: 2020-05-12 16:02 CEST (History)
5 users (show)

See Also:
What kind of report is it?: Bug Report
What type of bug is this?: 5: Major Usability: Impairs usability in key scenarios
Who will be affected by this bug?: 3: Will affect average number of installed domains
How will those affected feel about the bug?: 4: A User would return the product
User Pain: 0.343
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

Note You need to log in before you can comment on or make changes to this bug.
Description Daniel Tröder univentionstaff 2019-03-21 17:50:33 CET
Starting univention-upgrade. Current UCS version is 4.4-0 errata5

Checking for local repository:                          none
Checking for package updates:                           found

The following packages will be upgraded:
 libunivention-config0,python-univention,univention-config,python-univention-config-registry,univention-errata-level,univention-pam
Starting dist-update at Thu Mar 21 16:36:53 2019...
Starting package upgrade                                Traceback in univention-upgrade:
Traceback (most recent call last):
  File "/usr/sbin/univention-upgrade", line 441, in do_update
    update_available = performUpdate(options, checkForUpdates=options.check, silent=False)
  File "/usr/sbin/univention-upgrade", line 139, in performUpdate
    if func(options, checkForUpdates, silent):
  File "/usr/sbin/univention-upgrade", line 221, in do_package_updates
    os.environ['ADMINDIARY_CONTEXT'] = context_id
  File "/usr/lib/python2.7/os.py", line 473, in __setitem__
    putenv(key, item)
TypeError: putenv() argument 2 must be string, not None

---------------------------------------------------------------------

The reason is:

from univention.admindiary.client import write_event
write_event()
  -> write()
    -> write_entry():
      -> if entry.event_name in blocked_events:
            return
-> None
-> os.environ['..'] = None
-> TypeError

---------------------------------------------------------------------

Happens with newest appbox image: docker-test.software-univention.de/ucs-appbox-amd64:4.4-0
Comment 1 Daniel Tröder univentionstaff 2019-04-26 16:20:37 CEST
Dockerfile to reproduce:

FROM docker-test.software-univention.de/ucs-appbox-amd64:4.4-0
RUN /usr/sbin/univention-upgrade || (cat /var/log/univention/updater.log; exit 1)
Comment 2 Daniel Tröder univentionstaff 2019-04-26 16:24:12 CEST
FROM docker-test.software-univention.de/ucs-appbox-amd64:4.4-0
RUN export DEBIAN_FRONTEND=noninteractive; /usr/sbin/univention-upgrade --ignoressh --ignoreterm --noninteractive --updateto="$(ucr get version/version)-99" || (cat /var/log/univention/updater.log; exit 1)
Comment 3 Daniel Tröder univentionstaff 2019-04-26 16:31:28 CEST
Happens during image build time, 1-liner:

# echo -e 'FROM docker-test.software-univention.de/ucs-appbox-amd64:4.4-0\nRUN univention-upgrade --noninteractive || (cat /var/log/univention/updater.log; exit 1)' | docker build -
Comment 4 Arvid Requate univentionstaff 2019-05-13 13:55:24 CEST
There must have been a traceback in univention.admindiary.client.write which should be logged in /var/log/univention/admindiary.log.

Reproducable with this command:

echo -e 'FROM docker-test.software-univention.de/ucs-appbox-amd64:4.4-0\nRUN echo "deb [trusted=yes] http://192.168.0.10/build2/ ucs_4.4-0-errata4.4-0/all/" >> /etc/apt/sources.list.d/30_test.list; univention-upgrade --noninteractive || (cat /var/log/univention/updater.log; echo "==="; cat /var/log/univention/admindiary.log; exit 1)' | docker build -

admindiary.log contains this line:

	5 client 19-03-07 20:29:49 [ ERROR]: write_entry failed! Args have to be "dict of string/string"
Comment 5 Arvid Requate univentionstaff 2019-05-13 15:22:07 CEST
I improved the log messages, now it would have logged this to admindiary.log:

===============================================================================
  2991 client       19-03-07 21:06:00 [   ERROR]: write_entry failed! Args have to be "dict of string/string", but is <type 'dict'> ({'hostname': None})
  2991 client       19-03-07 21:06:00 [   ERROR]: Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/univention/admindiary/client.py", line 48, in wrapper
    return f(*args, **kwds)
  File "/usr/lib/pymodules/python2.7/univention/admindiary/client.py", line 101, in write_entry
    entry.assert_types()
  File "/usr/lib/pymodules/python2.7/univention/admindiary/__init__.py", line 108, in assert_types
    raise TypeError('Args have to be "dict of string/string", but is %s (%s)' % (type(self.args), self.args))
TypeError: Args have to be "dict of string/string", but is <type 'dict'> ({'hostname': None})
===============================================================================

After fixing that by using socket.gethostname() instead of configRegistry.get('hostname') I run into the next traceback:

===============================================================================
  5974 client       19-03-07 21:15:47 [   ERROR]: write_entry failed! [Errno 2] No such file or directory
  5974 client       19-03-07 21:15:47 [   ERROR]: Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/univention/admindiary/client.py", line 48, in wrapper
    return f(*args, **kwds)
  File "/usr/lib/pymodules/python2.7/univention/admindiary/client.py", line 107, in write_entry
    emitter.emit(body)
  File "/usr/lib/pymodules/python2.7/univention/admindiary/client.py", line 64, in emit
    self.handler = SysLogHandler(address='/dev/log', facility='user')
  File "/usr/lib/python2.7/logging/handlers.py", line 761, in __init__
    self._connect_unixsocket(address)
  File "/usr/lib/python2.7/logging/handlers.py", line 789, in _connect_unixsocket
    self.socket.connect(address)
  File "/usr/lib/python2.7/socket.py", line 228, in meth
    return getattr(self._sock,name)(*args)
error: [Errno 2] No such file or directory
===============================================================================

499362294a | Improve robustness and traceback logging
8542629bb0 | Fix traceback in admindiary.client.write_event() occurring
             in Docker containers during docker build
57107e5bb7 | Advisories
Comment 6 Daniel Tröder univentionstaff 2019-05-13 17:00:41 CEST
Works for me:

# echo -e "deb [trusted=yes] http://192.168.0.10/build2/ ucs_4.4-0-errata4.4-0/all/\ndeb [trusted=yes] http://192.168.0.10/build2/ ucs_4.4-0-errata4.4-0/\$(ARCH)/" > 30_test.list
# cat << EOF > Dockerfile
FROM docker-test.software-univention.de/ucs-appbox-amd64:4.4-0
ADD 30_test.list /etc/apt/sources.list.d
RUN export DEBIAN_FRONTEND=noninteractive; apt-get update; apt-get install univention-updater univention-admin-diary-client python-univention-admin-diary; dpkg -l | egrep "univention-updater|univention-admin-diary"
RUN export DEBIAN_FRONTEND=noninteractive; univention-upgrade --noninteractive || (echo "== failed, now updater.log: =="; cat /var/log/univention/updater.log; echo "== end updater.log =="; exit 1)
EOF
# docker build .

→ no exception, image builds without problems
Comment 7 Felix Botner univentionstaff 2019-05-14 14:23:18 CEST
i can still reproduce this

normal UCS (with errata)

-> ucr set admin/diary/reject="UPDATE_STARTED"
-> univention-upgrade

Starting package upgrade                                Traceback in univention-upgrade:
Traceback (most recent call last):
  File "/usr/sbin/univention-upgrade", line 443, in do_update
    update_available = performUpdate(options, checkForUpdates=options.check, silent=False)
  File "/usr/sbin/univention-upgrade", line 140, in performUpdate
    if func(options, checkForUpdates, silent):
  File "/usr/sbin/univention-upgrade", line 223, in do_package_updates
    os.environ['ADMINDIARY_CONTEXT'] = context_id
  File "/usr/lib/python2.7/os.py", line 473, in __setitem__
    putenv(key, item)
TypeError: putenv() argument 2 must be string, not None

Admin Diary write_entry returns None in case the event is blocked.


We have to check context_id is not None in univention-updater (python/univention-updater and python/univention-upgrade) before setting the ENV variable.
Comment 8 Daniel Tröder univentionstaff 2019-05-14 14:48:12 CEST
(In reply to Felix Botner from comment #7)
> We have to check context_id is not None in univention-updater
> (python/univention-updater and python/univention-upgrade) before setting the
> ENV variable.
My workaround in OX (https://git.knut.univention.de/univention/open-xchange/appsuite/blob/docker/docker/stage1/setup_ucs.sh) is to replace 
   ... = context_id
with
   ... = str(context_id)
Comment 9 Arvid Requate univentionstaff 2019-05-14 16:15:05 CEST
6fbc5830d4 | fix for univention-updater
972ebc8341 | Advisory
Comment 10 Felix Botner univentionstaff 2019-05-15 11:28:09 CEST
OK - univention-updater
OK - univention-admin-diary
OK - yaml

4.4-0 ucs docker images still broken though
Comment 12 Florian Best univentionstaff 2019-05-21 13:27:24 CEST
*** Bug 49518 has been marked as a duplicate of this bug. ***
Comment 13 Florian Best univentionstaff 2019-05-21 14:06:49 CEST
Workaround (untested):
sed -i "s#os.environ['ADMINDIARY_CONTEXT'] = context_id#os.environ['ADMINDIARY_CONTEXT'] = str(context_id)#g" /usr/sbin/univention-upgrade /usr/sbin/univention-updater
Comment 14 Arvid Requate univentionstaff 2020-05-12 16:02:15 CEST
The brackets need some escaping for this to work:

sed -i "s|os.environ\['ADMINDIARY_CONTEXT'\] = context_id|os.environ\['ADMINDIARY_CONTEXT'\] = str(context_id)|g" \
  /usr/sbin/univention-upgrade /usr/share/univention-updater/univention-updater