"AttributeError: 'str' object has no attribute 'content_type' in functional tests

Bug #1850558 reported by Slawek Kaplonski
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
neutron
Fix Released
Medium
Rodolfo Alonso

Bug Description

It happen few times already in functional and fullstack tests that we had failure like:

2019-10-24 11:57:35.161 5434 ERROR neutron Traceback (most recent call last):
2019-10-24 11:57:35.161 5434 ERROR neutron File "/usr/lib/python3.6/runpy.py", line 193, in _run_module_as_main
2019-10-24 11:57:35.161 5434 ERROR neutron "__main__", mod_spec)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/usr/lib/python3.6/runpy.py", line 85, in _run_code
2019-10-24 11:57:35.161 5434 ERROR neutron exec(code, run_globals)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/home/zuul/src/opendev.org/openstack/neutron/.tox/dsvm-functional/lib/python3.6/site-packages/stestr/subunit_runner/run.py", line 99, in <module>
2019-10-24 11:57:35.161 5434 ERROR neutron main()
2019-10-24 11:57:35.161 5434 ERROR neutron File "/home/zuul/src/opendev.org/openstack/neutron/.tox/dsvm-functional/lib/python3.6/site-packages/stestr/subunit_runner/run.py", line 90, in main
2019-10-24 11:57:35.161 5434 ERROR neutron testRunner=partial(runner, stdout=sys.stdout))
2019-10-24 11:57:35.161 5434 ERROR neutron File "/home/zuul/src/opendev.org/openstack/neutron/.tox/dsvm-functional/lib/python3.6/site-packages/stestr/subunit_runner/program.py", line 185, in __init__
2019-10-24 11:57:35.161 5434 ERROR neutron self.runTests()
2019-10-24 11:57:35.161 5434 ERROR neutron File "/home/zuul/src/opendev.org/openstack/neutron/.tox/dsvm-functional/lib/python3.6/site-packages/stestr/subunit_runner/program.py", line 226, in runTests
2019-10-24 11:57:35.161 5434 ERROR neutron self.result = testRunner.run(self.test)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/home/zuul/src/opendev.org/openstack/neutron/.tox/dsvm-functional/lib/python3.6/site-packages/stestr/subunit_runner/run.py", line 52, in run
2019-10-24 11:57:35.161 5434 ERROR neutron test(result)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/usr/lib/python3.6/unittest/suite.py", line 84, in __call__
2019-10-24 11:57:35.161 5434 ERROR neutron return self.run(*args, **kwds)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/usr/lib/python3.6/unittest/suite.py", line 122, in run
2019-10-24 11:57:35.161 5434 ERROR neutron test(result)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/usr/lib/python3.6/unittest/suite.py", line 84, in __call__
2019-10-24 11:57:35.161 5434 ERROR neutron return self.run(*args, **kwds)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/usr/lib/python3.6/unittest/suite.py", line 122, in run
2019-10-24 11:57:35.161 5434 ERROR neutron test(result)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/usr/lib/python3.6/unittest/suite.py", line 84, in __call__
2019-10-24 11:57:35.161 5434 ERROR neutron return self.run(*args, **kwds)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/usr/lib/python3.6/unittest/suite.py", line 122, in run
2019-10-24 11:57:35.161 5434 ERROR neutron test(result)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/usr/lib/python3.6/unittest/suite.py", line 84, in __call__
2019-10-24 11:57:35.161 5434 ERROR neutron return self.run(*args, **kwds)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/usr/lib/python3.6/unittest/suite.py", line 122, in run
2019-10-24 11:57:35.161 5434 ERROR neutron test(result)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/home/zuul/src/opendev.org/openstack/neutron/.tox/dsvm-functional/lib/python3.6/site-packages/unittest2/case.py", line 673, in __call__
2019-10-24 11:57:35.161 5434 ERROR neutron return self.run(*args, **kwds)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/home/zuul/src/opendev.org/openstack/neutron/.tox/dsvm-functional/lib/python3.6/site-packages/testtools/testcase.py", line 671, in run
2019-10-24 11:57:35.161 5434 ERROR neutron return run_test.run(result)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/home/zuul/src/opendev.org/openstack/neutron/.tox/dsvm-functional/lib/python3.6/site-packages/testtools/runtest.py", line 80, in run
2019-10-24 11:57:35.161 5434 ERROR neutron return self._run_one(actual_result)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/home/zuul/src/opendev.org/openstack/neutron/.tox/dsvm-functional/lib/python3.6/site-packages/testtools/runtest.py", line 94, in _run_one
2019-10-24 11:57:35.161 5434 ERROR neutron return self._run_prepared_result(ExtendedToOriginalDecorator(result))
2019-10-24 11:57:35.161 5434 ERROR neutron File "/home/zuul/src/opendev.org/openstack/neutron/.tox/dsvm-functional/lib/python3.6/site-packages/testtools/runtest.py", line 108, in _run_prepared_result
2019-10-24 11:57:35.161 5434 ERROR neutron self._run_core()
2019-10-24 11:57:35.161 5434 ERROR neutron File "/home/zuul/src/opendev.org/openstack/neutron/.tox/dsvm-functional/lib/python3.6/site-packages/testtools/runtest.py", line 162, in _run_core
2019-10-24 11:57:35.161 5434 ERROR neutron details=self.case.getDetails())
2019-10-24 11:57:35.161 5434 ERROR neutron File "/home/zuul/src/opendev.org/openstack/neutron/.tox/dsvm-functional/lib/python3.6/site-packages/testtools/testresult/real.py", line 1446, in addSuccess
2019-10-24 11:57:35.161 5434 ERROR neutron return self.decorated.addSuccess(test, details=details)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/home/zuul/src/opendev.org/openstack/neutron/.tox/dsvm-functional/lib/python3.6/site-packages/subunit/test_results.py", line 147, in addSuccess
2019-10-24 11:57:35.161 5434 ERROR neutron return self.super.addSuccess(test, details=details)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/home/zuul/src/opendev.org/openstack/neutron/.tox/dsvm-functional/lib/python3.6/site-packages/subunit/test_results.py", line 72, in addSuccess
2019-10-24 11:57:35.161 5434 ERROR neutron return self.decorated.addSuccess(test, details=details)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/home/zuul/src/opendev.org/openstack/neutron/.tox/dsvm-functional/lib/python3.6/site-packages/testtools/testresult/real.py", line 1446, in addSuccess
2019-10-24 11:57:35.161 5434 ERROR neutron return self.decorated.addSuccess(test, details=details)
2019-10-24 11:57:35.161 5434 ERROR neutron File "/home/zuul/src/opendev.org/openstack/neutron/.tox/dsvm-functional/lib/python3.6/site-packages/testtools/testresult/real.py", line 1638, in addSuccess
2019-10-24 11:57:35.161 5434 ERROR neutron self._convert(test, None, details, 'success')
2019-10-24 11:57:35.161 5434 ERROR neutron File "/home/zuul/src/opendev.org/openstack/neutron/.tox/dsvm-functional/lib/python3.6/site-packages/testtools/testresult/real.py", line 1604, in _convert
2019-10-24 11:57:35.161 5434 ERROR neutron mime_type = repr(content.content_type)
2019-10-24 11:57:35.161 5434 ERROR neutron AttributeError: 'str' object has no attribute 'content_type'

Logstash query
http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22AttributeError%3A%20'str'%20object%20has%20no%20attribute%20'content_type'%5C%22

Revision history for this message
Lajos Katona (lajos-katona) wrote :

Interestingly seems to happen on both py3 and py27, and in some cases the tests seems to be failing (at least the call to testtools.testresult.real._convert is coming from addError, see[1]) in some cases the test is passing (the call to _convert is coming from addSuccess, see [2])

[1]: https://github.com/testing-cabal/testtools/blob/master/testtools/testresult/real.py#L1590
[2]: https://github.com/testing-cabal/testtools/blob/master/testtools/testresult/real.py#L1638

Revision history for this message
Rodolfo Alonso (rodolfo-alonso-hernandez) wrote :

Hello:

This problem, happening both in functional and fullstack tests, is due to the early closure of the rootwrap daemon. E.g.: in [1] we can see this error happening at 13:57:19.363. In the journal logs [2] we can see at this exact time how the same neutron-rootwrap-daemon running the commands being executed in this test (PID 5931) receives a 2 signal and closes the socket [3]. The command
in execution exists and the test ends at this point successfully (I don't understand why!) and the error/exception is not handled correctly.

In the code there is only one place where the SIGINT signal is sent [4]. RootwrapClass.shutdown() is executed when a timeout occurs (RootwrapClass.handle_timeout()). But each new command executed from the client side will reset the timeout, that's why I don't understand why this is happening.

To avoid this issue, during the execution of FT and fullstack tests, we should mock RootwrapClass.handle_timeout to avoid shutting down the rootwrap daemon because of a command timeout. But we should keep shutdown to allow the client to stop the daemon manually when needed.

[1] https://fa41114c73dc4ffe3f14-2bb0e09cfc1bf1e619272dff8ccf0e99.ssl.cf2.rackcdn.com/683128/2/check/neutron-functional/7cd4a45/controller/logs/dsvm-functional-logs/neutron.tests.functional.agent.test_l2_lb_agent.LinuxBridgeAgentTests.test_vlan_QinQ_subinterfaces.txt.gz
[2] https://fa41114c73dc4ffe3f14-2bb0e09cfc1bf1e619272dff8ccf0e99.ssl.cf2.rackcdn.com/683128/2/check/neutron-functional/7cd4a45/controller/logs/journal_log.txt.gz
[3] https://github.com/openstack/oslo.rootwrap/blob/6c5995a952f87d642d5df4003ed7dae60798d712/oslo_rootwrap/daemon.py#L196
[4] https://github.com/openstack/oslo.rootwrap/blob/6c5995a952f87d642d5df4003ed7dae60798d712/oslo_rootwrap/daemon.py#L115

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to neutron (master)

Fix proposed to branch: master
Review: https://review.opendev.org/692347

Changed in neutron:
assignee: nobody → Rodolfo Alonso (rodolfo-alonso-hernandez)
status: Confirmed → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to neutron (master)

Reviewed: https://review.opendev.org/692347
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=721887305038fe4449083eb6c33f355232c73555
Submitter: Zuul
Branch: master

commit 721887305038fe4449083eb6c33f355232c73555
Author: Rodolfo Alonso Hernandez <email address hidden>
Date: Thu Oct 31 11:42:47 2019 +0000

    Set rootwrap daemon timeout for fullstack and functional tests

    Set a big timeout for rootwrap daemon in functional and fullstack
    tests. The value defined in 7800, the same as the Zuul jobs
    timeout.

    This timeout increase will prevent the daemon to close when
    executing a test root command, as described in the bug. An
    unexpected rootwrap daemon closure is not considered as a normal
    event during the test execution.

    The default value set in the configuration file is 600 seconds, the
    same as daemon default value. This timeout is increased only when
    OS_SUDO_TESTING=1, that means functional and fullstack tests, when
    using the script "tools/deploy_rootwrap.sh".

    Change-Id: I691300a4e9a7cccd8887bc8f95ba9cea32988bac
    Closes-Bug: #1850558

Changed in neutron:
status: In Progress → Fix Released
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to neutron (stable/train)

Fix proposed to branch: stable/train
Review: https://review.opendev.org/692788

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to neutron (stable/stein)

Fix proposed to branch: stable/stein
Review: https://review.opendev.org/692789

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to neutron (stable/train)

Reviewed: https://review.opendev.org/692788
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=6236d78a4a60eb5f56f218b1e6aa83bb307ba0c5
Submitter: Zuul
Branch: stable/train

commit 6236d78a4a60eb5f56f218b1e6aa83bb307ba0c5
Author: Rodolfo Alonso Hernandez <email address hidden>
Date: Thu Oct 31 11:42:47 2019 +0000

    Set rootwrap daemon timeout for fullstack and functional tests

    Set a big timeout for rootwrap daemon in functional and fullstack
    tests. The value defined in 7800, the same as the Zuul jobs
    timeout.

    This timeout increase will prevent the daemon to close when
    executing a test root command, as described in the bug. An
    unexpected rootwrap daemon closure is not considered as a normal
    event during the test execution.

    The default value set in the configuration file is 600 seconds, the
    same as daemon default value. This timeout is increased only when
    OS_SUDO_TESTING=1, that means functional and fullstack tests, when
    using the script "tools/deploy_rootwrap.sh".

    Change-Id: I691300a4e9a7cccd8887bc8f95ba9cea32988bac
    Closes-Bug: #1850558
    (cherry picked from commit 721887305038fe4449083eb6c33f355232c73555)

tags: added: in-stable-train
tags: added: in-stable-stein
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to neutron (stable/stein)

Reviewed: https://review.opendev.org/692789
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=57ec2f460f1b740585c6e68ee754bc0e4b9dd26c
Submitter: Zuul
Branch: stable/stein

commit 57ec2f460f1b740585c6e68ee754bc0e4b9dd26c
Author: Rodolfo Alonso Hernandez <email address hidden>
Date: Thu Oct 31 11:42:47 2019 +0000

    Set rootwrap daemon timeout for fullstack and functional tests

    Set a big timeout for rootwrap daemon in functional and fullstack
    tests. The value defined in 7800, the same as the Zuul jobs
    timeout.

    This timeout increase will prevent the daemon to close when
    executing a test root command, as described in the bug. An
    unexpected rootwrap daemon closure is not considered as a normal
    event during the test execution.

    The default value set in the configuration file is 600 seconds, the
    same as daemon default value. This timeout is increased only when
    OS_SUDO_TESTING=1, that means functional and fullstack tests, when
    using the script "tools/deploy_rootwrap.sh".

    Change-Id: I691300a4e9a7cccd8887bc8f95ba9cea32988bac
    Closes-Bug: #1850558
    (cherry picked from commit 721887305038fe4449083eb6c33f355232c73555)

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/neutron 14.0.4

This issue was fixed in the openstack/neutron 14.0.4 release.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/neutron 15.0.1

This issue was fixed in the openstack/neutron 15.0.1 release.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/neutron 16.0.0.0b1

This issue was fixed in the openstack/neutron 16.0.0.0b1 development milestone.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.