Bug 52686 - Python3 UMC Modules don't log anything
Python3 UMC Modules don't log anything
Status: CLOSED FIXED
Product: UCS
Classification: Unclassified
Component: UMC (Generic)
UCS 5.0
Other Linux
: P5 major (vote)
: UCS 5.0
Assigned To: Florian Best
Arvid Requate
:
Depends on:
Blocks: 51324
  Show dependency treegraph
 
Reported: 2021-01-25 17:44 CET by Arvid Requate
Modified: 2021-05-25 16:02 CEST (History)
1 user (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
Workaround-for-python3-umc-module-logging.patch (723 bytes, patch)
2021-01-25 17:44 CET, Arvid Requate
Details | Diff
Workaround-for-python3-umc-module-logging-2.patch (1.07 KB, patch)
2021-01-25 18:37 CET, Arvid Requate
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Arvid Requate univentionstaff 2021-01-25 17:44:34 CET
Created attachment 10603 [details]
Workaround-for-python3-umc-module-logging.patch

On my UCS 5.0 beta system I have a bunch on UMC modules running, some with python2.7 and some with python3. The ones running with python3 only log exactly one line into their respective log file:

DEBUG_INIT

The attached patch shows the line that breaks the logging. No clue why.
Comment 1 Arvid Requate univentionstaff 2021-01-25 18:07:35 CET
A quick experiment with "kill -HUP" against the module PID (to trigger log_reopen() in daemon mode) shows another defect of the python3 UMC modules. After receiving this signal the module turns into a fast spinning wheel of fire, eternally logging:
===================================================================
25.01.21 17:57:56.934  MAIN        ( ERROR   ) : Cannot accept new connection: [Errno 88] Socket operation on non-socket
25.01.21 17:57:56.934  MAIN        ( ERROR   ) : Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/univention/management/console/protocol/server.py", line 402, in _connection
    socket, addr = socket.accept()
  File "/usr/lib/python3.7/socket.py", line 212, in accept
    fd, addr = self._accept()
OSError: [Errno 88] Socket operation on non-socket

25.01.21 17:57:56.934  MAIN        ( ERROR   ) : Cannot accept new connection: [Errno 88] Socket operation on non-socket
25.01.21 17:57:56.934  MAIN        ( ERROR   ) : Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/univention/management/console/protocol/server.py", line 402, in _connection
    socket, addr = socket.accept()
  File "/usr/lib/python3.7/socket.py", line 212, in accept
    fd, addr = self._accept()
OSError: [Errno 88] Socket operation on non-socket
===================================================================
Note: this was all in the same millisecond.
Comment 2 Arvid Requate univentionstaff 2021-01-25 18:37:32 CET
Created attachment 10604 [details]
Workaround-for-python3-umc-module-logging-2.patch

Another possible workaround for the original topic. Thanks to Dirk Wiesenthal.
Comment 3 Florian Best univentionstaff 2021-01-26 10:39:49 CET
I think we should go with the second patch.
Finding the real cause maybe can be done after the release?
Comment 4 Arvid Requate univentionstaff 2021-01-26 11:45:30 CET
I'd be fine with that, but I have no clue if this breaks anything.
I guess it will be fine until somebody would actually use the logging
of the notifier, but that would be a developer, not a user.
Comment 5 Florian Best univentionstaff 2021-01-29 13:29:51 CET
commit a4073d4a3d11fb704e4650cfb35469ca87601828

    Bug #52686: fix logging of univention-debug
    
    python-notifier opens logging streams during import (instead of during
    notifier.init(), grr).
    In combination with python-daemon, these file descriptor (for
    /var/log/python-notifier.log) are closed during daemonizing.
    This somehow affects univention.debug when we remove the notifier.log
    handler before initializing univention.debug. Only in Python 3.
Comment 6 Arvid Requate univentionstaff 2021-02-03 11:57:31 CET
Works for normal logging and tracebacks.
Changelog entry not required, interim bug.
Comment 7 Florian Best univentionstaff 2021-05-25 16:02:09 CEST
UCS 5.0 has been released:
 https://docs.software-univention.de/release-notes-5.0-0-en.html
 https://docs.software-univention.de/release-notes-5.0-0-de.html

If this error occurs again, please use "Clone This Bug".