Note: This is a public test instance of Red Hat Bugzilla. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback at bugzilla.redhat.com.

Bug 1705705

Summary: python-structlog FTBFS with Python 3.8
Product: [Fedora] Fedora Reporter: Miro Hrončok <mhroncok>
Component: python-structlogAssignee: Piotr Popieluch <piotr1212>
Status: CLOSED RAWHIDE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: high Docs Contact:
Priority: unspecified    
Version: rawhideCC: piotr1212
Target Milestone: ---Keywords: Reopened
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-01-06 11:04:08 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1750908, 1750909, 1686977, 1773370    
Attachments:
Description Flags
Full log from Copr
none
Full log from Copr for 19.1.0-2.fc31 none

Description Miro Hrončok 2019-05-02 19:27:28 UTC
Created attachment 1561938 [details]
Full log from Copr

python-structlog 18.2.0-4.fc31 fails to build with Python 3.8.0a3:

=================================== FAILURES ===================================
______________________ TestLoggerFactory.test_find_caller ______________________

self = <tests.test_stdlib.TestLoggerFactory object at 0x7f967e0380a0>
monkeypatch = <_pytest.monkeypatch.MonkeyPatch object at 0x7f967e038400>

    def test_find_caller(self, monkeypatch):
        logger = LoggerFactory()()
        log_handle = call_recorder(lambda x: None)
        monkeypatch.setattr(logger, "handle", log_handle)
>       logger.error("Test")

../tests/test_stdlib.py:114: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
/usr/lib64/python3.8/logging/__init__.py:1474: in error
    self._log(ERROR, msg, args, **kwargs)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <_FixedFindCallerLogger tests.test_stdlib (WARNING)>, level = 40
msg = 'Test', args = (), exc_info = None, extra = None, stack_info = False
stacklevel = 1

    def _log(self, level, msg, args, exc_info=None, extra=None, stack_info=False,
             stacklevel=1):
        """
        Low-level logging routine which creates a LogRecord and then calls
        all the handlers of this logger to handle the record.
        """
        sinfo = None
        if _srcfile:
            #IronPython doesn't track Python frames, so findCaller raises an
            #exception on some versions of IronPython. We trap it here so that
            #IronPython can use logging.
            try:
>               fn, lno, func, sinfo = self.findCaller(stack_info, stacklevel)
E               TypeError: findCaller() takes from 1 to 2 positional arguments but 3 were given

/usr/lib64/python3.8/logging/__init__.py:1576: TypeError
______________________ TestProcessorFormatter.test_native ______________________

self = <tests.test_stdlib.TestProcessorFormatter object at 0x7f967ceebee0>
configure_for_pf = None
capsys = <_pytest.capture.CaptureFixture object at 0x7f967ceeb520>

    def test_native(self, configure_for_pf, capsys):
        """
        If the log entry comes from structlog, it's unpackaged and processed.
        """
        configure_logging(None)
    
>       get_logger().warning("foo")

../tests/test_stdlib.py:675: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
structlog/stdlib.py:75: in warning
    return self._proxy_to_logger("warning", event, *args, **kw)
structlog/stdlib.py:118: in _proxy_to_logger
    return super(BoundLogger, self)._proxy_to_logger(
structlog/_base.py:192: in _proxy_to_logger
    return getattr(self._logger, method_name)(*args, **kw)
/usr/lib64/python3.8/logging/__init__.py:1457: in warning
    self._log(WARNING, msg, args, **kwargs)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <_FixedFindCallerLogger tests.test_stdlib (DEBUG)>, level = 30
msg = {'event': 'foo', 'level': 'warning'}, args = (), exc_info = None
extra = {'_logger': <_FixedFindCallerLogger tests.test_stdlib (DEBUG)>, '_name': 'warning'}
stack_info = False, stacklevel = 1

    def _log(self, level, msg, args, exc_info=None, extra=None, stack_info=False,
             stacklevel=1):
        """
        Low-level logging routine which creates a LogRecord and then calls
        all the handlers of this logger to handle the record.
        """
        sinfo = None
        if _srcfile:
            #IronPython doesn't track Python frames, so findCaller raises an
            #exception on some versions of IronPython. We trap it here so that
            #IronPython can use logging.
            try:
>               fn, lno, func, sinfo = self.findCaller(stack_info, stacklevel)
E               TypeError: findCaller() takes from 1 to 2 positional arguments but 3 were given

/usr/lib64/python3.8/logging/__init__.py:1576: TypeError


This might or might not be related to Python 3.8.
Full log attached.

Comment 1 Piotr Popieluch 2019-05-02 20:08:55 UTC
Updated in Rawhide to 19.1.0 which seems to work with Python 3.8

Comment 2 Miro Hrončok 2019-05-02 23:21:01 UTC
Thanks. However it did not help.

python-structlog 19.1.0-2.fc31 

+ /usr/bin/python3 -m pytest ../tests
============================= test session starts ==============================
platform linux -- Python 3.8.0a3, pytest-4.4.1, py-1.8.0, pluggy-0.9.0
rootdir: /builddir/build/BUILD/structlog-19.1.0, inifile: setup.cfg
collected 258 items

../tests/test_base.py ..................                                 [  6%]
../tests/test_config.py ................................                 [ 19%]
../tests/test_dev.py .................                                   [ 25%]
../tests/test_frames.py ............                                     [ 30%]
../tests/test_generic.py ..                                              [ 31%]
../tests/test_loggers.py ..................                              [ 38%]
../tests/test_processors.py ..............ss............................ [ 55%]
...                                                                      [ 56%]
../tests/test_stdlib.py .....F.......................................... [ 75%]
..............F                                                          [ 81%]
../tests/test_threadlocal.py ............s....                           [ 87%]
../tests/test_twisted.py ........x....................                   [ 98%]
../tests/test_utils.py ...                                               [100%]

=================================== FAILURES ===================================
______________________ TestLoggerFactory.test_find_caller ______________________

self = <tests.test_stdlib.TestLoggerFactory object at 0x7fec4dbd4550>
monkeypatch = <_pytest.monkeypatch.MonkeyPatch object at 0x7fec4dbd47f0>

    def test_find_caller(self, monkeypatch):
        logger = LoggerFactory()()
        log_handle = call_recorder(lambda x: None)
        monkeypatch.setattr(logger, "handle", log_handle)
>       logger.error("Test")

../tests/test_stdlib.py:114: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
/usr/lib64/python3.8/logging/__init__.py:1474: in error
    self._log(ERROR, msg, args, **kwargs)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <_FixedFindCallerLogger tests.test_stdlib (WARNING)>, level = 40
msg = 'Test', args = (), exc_info = None, extra = None, stack_info = False
stacklevel = 1

    def _log(self, level, msg, args, exc_info=None, extra=None, stack_info=False,
             stacklevel=1):
        """
        Low-level logging routine which creates a LogRecord and then calls
        all the handlers of this logger to handle the record.
        """
        sinfo = None
        if _srcfile:
            #IronPython doesn't track Python frames, so findCaller raises an
            #exception on some versions of IronPython. We trap it here so that
            #IronPython can use logging.
            try:
>               fn, lno, func, sinfo = self.findCaller(stack_info, stacklevel)
E               TypeError: findCaller() takes from 1 to 2 positional arguments but 3 were given

/usr/lib64/python3.8/logging/__init__.py:1576: TypeError
______________________ TestProcessorFormatter.test_native ______________________

self = <tests.test_stdlib.TestProcessorFormatter object at 0x7fec4ca4b070>
configure_for_pf = None
capsys = <_pytest.capture.CaptureFixture object at 0x7fec4ca4b220>

    def test_native(self, configure_for_pf, capsys):
        """
        If the log entry comes from structlog, it's unpackaged and processed.
        """
        configure_logging(None)
    
>       get_logger().warning("foo")

../tests/test_stdlib.py:710: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
structlog/stdlib.py:75: in warning
    return self._proxy_to_logger("warning", event, *args, **kw)
structlog/stdlib.py:118: in _proxy_to_logger
    return super(BoundLogger, self)._proxy_to_logger(
structlog/_base.py:192: in _proxy_to_logger
    return getattr(self._logger, method_name)(*args, **kw)
/usr/lib64/python3.8/logging/__init__.py:1457: in warning
    self._log(WARNING, msg, args, **kwargs)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <_FixedFindCallerLogger tests.test_stdlib (DEBUG)>, level = 30
msg = {'event': 'foo', 'level': 'warning'}, args = (), exc_info = None
extra = {'_logger': <_FixedFindCallerLogger tests.test_stdlib (DEBUG)>, '_name': 'warning'}
stack_info = False, stacklevel = 1

    def _log(self, level, msg, args, exc_info=None, extra=None, stack_info=False,
             stacklevel=1):
        """
        Low-level logging routine which creates a LogRecord and then calls
        all the handlers of this logger to handle the record.
        """
        sinfo = None
        if _srcfile:
            #IronPython doesn't track Python frames, so findCaller raises an
            #exception on some versions of IronPython. We trap it here so that
            #IronPython can use logging.
            try:
>               fn, lno, func, sinfo = self.findCaller(stack_info, stacklevel)
E               TypeError: findCaller() takes from 1 to 2 positional arguments but 3 were given

/usr/lib64/python3.8/logging/__init__.py:1576: TypeError
=========================== short test summary info ============================
SKIPPED [1] tests/test_processors.py:193: simplejson is missing.
SKIPPED [1] tests/test_processors.py:208: python-rapidjson is missing.
SKIPPED [1] tests/test_threadlocal.py:208: Needs greenlet.
XFAIL ../tests/test_twisted.py::TestExtractStuffAndWhy::test_recognizesErrorsAndCleansThem
  Py3 does not allow for cleaning exc_info
FAILED ../tests/test_stdlib.py::TestLoggerFactory::test_find_caller
FAILED ../tests/test_stdlib.py::TestProcessorFormatter::test_native
========== 2 failed, 252 passed, 3 skipped, 1 xfailed in 1.27 seconds ==========

Comment 3 Miro Hrončok 2019-05-02 23:21:31 UTC
Created attachment 1562012 [details]
Full log from Copr for 19.1.0-2.fc31

Comment 4 Piotr Popieluch 2019-05-03 12:07:31 UTC
I assumed Rawhide was already on 3.8. Submitted a patch upstream, will wait for response. https://github.com/hynek/structlog/pull/208

Comment 5 Miro Hrončok 2019-05-03 12:24:37 UTC
Oh, sorry for the confusion.

Comment 6 Miro Hrončok 2019-07-10 10:16:32 UTC
Merged upstream, please backport. No need to bump and build.

Comment 7 Ben Cotton 2019-08-13 16:55:13 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 31 development cycle.
Changing version to '31'.

Comment 8 Ben Cotton 2019-08-13 19:04:27 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 31 development cycle.
Changing version to 31.

Comment 9 Miro Hrončok 2019-08-14 22:24:24 UTC
The coordinated rebuild of Python 3.8 has started in the `f32-python` side tag.

If you figure out how to rebuild this package, please don't rebuild it in regular rawhide, but use the side tag instead:

    on branch master:
    $ fedpkg build --target=f32-python

To wait for a build to show up in the side tag, do:

    $ koji wait-repo f32-python --build=<nvr>

Where <nvr> is name-version-release of the source package, e.g. python-foo-1.1-2.fc32.

An updated mock config is posted at:
http://copr.fedorainfracloud.org/coprs/g/python/python3.8/

Note that it will take a while before the essential packages are rebuilt, so don't expect all your dependencies to be available right away.

Thanks. Let us know if you need up to date info, or if you have any questions.



PS this message is mass posted to all the bugs that block the PYTHON38 bug. If this is also a Fedora 31 FTBFS bug and you manage to fix it, you can do a f31 build as usual:

    on branch f31:
    $ fedpkg build

Comment 10 Miro Hrončok 2019-08-21 16:35:06 UTC
The f32-python side tag has been merged. In order to rebuild the package, do it in regular rawhide, but please wait until python3-3.8 is tagged:

  $ koji wait-repo f32-build --build python3-3.8.0~b3-3.fc32


If your built already started in f32-python, after it is finished, please tag it to rawhide with:

  $ koji tag-build f32-pending <nvr>

For example:

  $ koji tag-build f32-pending libreoffice-6.3.0.4-3.fc32

Thanks!

(This comment is mass posted to all bugzillas blocking the PYTHON38 tracking bug.)

Comment 11 Miro Hrončok 2019-08-21 17:29:11 UTC
(Python 3.8 has landed in the rawhide buildroot.)

Comment 12 Miro Hrončok 2019-09-16 07:52:51 UTC
This issue is blocking the Python 3.8 rebuilds. If this package won't build with 3.8, it won't be installable, along with all its dependent packages, in Fedora 32.
Furthermore, as it fails to install, its dependent packages will fail to install and/or build as well.

Could you please backport the upstream fix?

Comment 13 Miro Hrončok 2020-01-02 15:00:55 UTC
What is the plan? Do we keep the package and try to fix it, or abandon it and retire it instead?

Comment 14 Piotr Popieluch 2020-01-06 11:04:08 UTC
Updated the package, builds now.

Comment 15 Miro Hrončok 2020-01-06 11:12:21 UTC
Thank You, Piotr.