Metadata proxy process errors with binary user_data

Bug #1501772 reported by James Page
10
This bug affects 1 person
Affects Status Importance Assigned to Milestone
neutron
Fix Released
High
Henry Gessau
neutron (Ubuntu)
Fix Released
High
James Page

Bug Description

Boot instances with binary user data content (rather than simple text) is not happy right now:

2015-10-01 13:19:39.109 10854 DEBUG neutron.agent.metadata.namespace_proxy [-] {'date': 'Thu, 01 Oct 2015 13:19:39 GMT', 'status': '200', 'content-length': '979', 'content-type': 'text/plain; charset=UTF-8', 'content-location': u'http://169.254.169.254/openstack/2013-10-17/user_data'} _proxy_request /usr/lib/python2.7/dist-packages/neutron/agent/metadata/namespace_proxy.py:90
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy [-] Unexpected error.
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy Traceback (most recent call last):
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy File "/usr/lib/python2.7/dist-packages/neutron/agent/metadata/namespace_proxy.py", line 55, in __call__
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy req.body)
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy File "/usr/lib/python2.7/dist-packages/neutron/agent/metadata/namespace_proxy.py", line 91, in _proxy_request
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy LOG.debug(content)
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy File "/usr/lib/python2.7/logging/__init__.py", line 1437, in debug
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy msg, kwargs = self.process(msg, kwargs)
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy File "/usr/lib/python2.7/dist-packages/oslo_log/log.py", line 139, in process
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy msg = _ensure_unicode(msg)
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy File "/usr/lib/python2.7/dist-packages/oslo_log/log.py", line 113, in _ensure_unicode
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy errors='xmlcharrefreplace',
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy File "/usr/lib/python2.7/dist-packages/oslo_utils/encodeutils.py", line 43, in safe_decode
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy return text.decode(incoming, errors)
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy File "/usr/lib/python2.7/encodings/utf_8.py", line 16, in decode
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy return codecs.utf_8_decode(input, errors, True)
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy TypeError: don't know how to handle UnicodeDecodeError in error callback
2015-10-01 13:19:39.109 10854 ERROR neutron.agent.metadata.namespace_proxy
2015-10-01 13:19:39.112 10854 INFO neutron.wsgi [-] 192.168.21.15 - - [01/Oct/2015 13:19:39] "GET /openstack/2013-10-17/user_data HTTP/1.1" 500 343 0.014536

This is thrown be the log call just prior to it being served back to the instance.

ProblemType: Bug
DistroRelease: Ubuntu 15.10
Package: neutron-metadata-agent 2:7.0.0~b3-0ubuntu3
ProcVersionSignature: Ubuntu 4.2.0-11.13-generic 4.2.1
Uname: Linux 4.2.0-11-generic x86_64
ApportVersion: 2.19-0ubuntu1
Architecture: amd64
Date: Thu Oct 1 13:38:21 2015
Ec2AMI: ami-000005ce
Ec2AMIManifest: FIXME
Ec2AvailabilityZone: nova
Ec2InstanceType: m1.small.osci
Ec2Kernel: None
Ec2Ramdisk: None
JournalErrors: -- No entries --
PackageArchitecture: all
SourcePackage: neutron
UpgradeStatus: No upgrade log present (probably fresh install)
mtime.conffile..etc.neutron.metadata.agent.ini: 2015-10-01T13:18:25.075633

Revision history for this message
James Page (james-page) wrote :
summary: - Metadata proxy process fails to provide user_data
+ Metadata proxy process errors with binary user_data
Kyle Mestery (mestery)
tags: added: liberty-rc-potential
Changed in neutron:
importance: Undecided → High
Changed in neutron:
assignee: nobody → Ihar Hrachyshka (ihar-hrachyshka)
Revision history for this message
James Page (james-page) wrote :

I'm just re-deploying the environment where I saw this issue - some other bug reports for this error code would indicate that maybe the unicode package is not installed.

Revision history for this message
Ihar Hrachyshka (ihar-hrachyshka) wrote :

I have a test case to reproduce it.

Changed in neutron:
status: New → Confirmed
Revision history for this message
James Page (james-page) wrote :

Installing random unicode packages did not help.

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

Fix proposed to branch: master
Review: https://review.openstack.org/229958

Changed in neutron:
status: Confirmed → In Progress
Revision history for this message
Kyle Mestery (mestery) wrote :

James, any chance you can try the patch here [1] to see if it fixes the issue? Thanks to Ihar for the quick turnaround!

[1] https://review.openstack.org/#/c/229958/

Revision history for this message
James Page (james-page) wrote :

Kyle

Patch works OK for me.

Changed in neutron:
milestone: none → mitaka-1
Changed in neutron:
assignee: Ihar Hrachyshka (ihar-hrachyshka) → Cedric Brandily (cbrandily)
Changed in neutron:
assignee: Cedric Brandily (cbrandily) → Henry Gessau (gessau)
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to neutron (master)

Reviewed: https://review.openstack.org/229958
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=80e3d9be4923ecad17377b1d15c8392b8a43dac6
Submitter: Jenkins
Branch: master

commit 80e3d9be4923ecad17377b1d15c8392b8a43dac6
Author: Ihar Hrachyshka <email address hidden>
Date: Thu Oct 1 17:13:25 2015 +0200

    metadata: don't crash proxy on non-unicode user data

    We attempt to log every successful metadata response with LOG.debug. But
    as per oslo.log docs [1], we should make sure that what we pass into the
    library is unicode.

    Http.request returns a tuple of Response object and a string, which is
    bytes in Python 2.x [2].

    That's why we need to convert the response content to unicode before
    passing it into oslo.log.

    To achieve it, we utilize encodeutils.safe_decode with 'replace' errors
    handling strategy, so that we don't get exceptions on input that does
    not conform unicode.

    For the unit test case, we pass a string that is not expected to convert
    to unicode with errors='strict' strategy or similar, and check that we
    still don't crash.

    While at it, we remove a check for the number of log calls being
    triggered, because it's something that we should avoid validating in
    test cases, and it cannot trigger a real bug. The mock that was used to
    count the number would also hide the bug that we try to reproduce.

    Note that the bug does not require debug to be set because the crash
    occurs before oslo.log machinery decides it should not log the message.

    [1]: http://docs.openstack.org/developer/oslo.log/usage.html#no-more-implicit-conversion-to-unicode-str
    [2]: http://bitworking.org/projects/httplib2/doc/html/libhttplib2.html#httplib2.Http.request

    Closes-Bug: #1501772
    Change-Id: I6a32c40ff117fae43913386134c8981539697ce8

Changed in neutron:
status: In Progress → Fix Committed
James Page (james-page)
Changed in neutron (Ubuntu):
assignee: nobody → James Page (james-page)
importance: Undecided → High
status: New → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to neutron (stable/liberty)

Fix proposed to branch: stable/liberty
Review: https://review.openstack.org/230513

Thierry Carrez (ttx)
Changed in neutron:
milestone: mitaka-1 → liberty-rc2
no longer affects: neutron/liberty
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to neutron (stable/liberty)

Reviewed: https://review.openstack.org/230513
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=13b6d76da361178ea0b84baf4831a4c7f53e29c7
Submitter: Jenkins
Branch: stable/liberty

commit 13b6d76da361178ea0b84baf4831a4c7f53e29c7
Author: Ihar Hrachyshka <email address hidden>
Date: Thu Oct 1 17:13:25 2015 +0200

    metadata: don't crash proxy on non-unicode user data

    We attempt to log every successful metadata response with LOG.debug. But
    as per oslo.log docs [1], we should make sure that what we pass into the
    library is unicode.

    Http.request returns a tuple of Response object and a string, which is
    bytes in Python 2.x [2].

    That's why we need to convert the response content to unicode before
    passing it into oslo.log.

    To achieve it, we utilize encodeutils.safe_decode with 'replace' errors
    handling strategy, so that we don't get exceptions on input that does
    not conform unicode.

    For the unit test case, we pass a string that is not expected to convert
    to unicode with errors='strict' strategy or similar, and check that we
    still don't crash.

    While at it, we remove a check for the number of log calls being
    triggered, because it's something that we should avoid validating in
    test cases, and it cannot trigger a real bug. The mock that was used to
    count the number would also hide the bug that we try to reproduce.

    Note that the bug does not require debug to be set because the crash
    occurs before oslo.log machinery decides it should not log the message.

    [1]: http://docs.openstack.org/developer/oslo.log/usage.html#no-more-implicit-conversion-to-unicode-str
    [2]: http://bitworking.org/projects/httplib2/doc/html/libhttplib2.html#httplib2.Http.request

    Closes-Bug: #1501772
    Change-Id: I6a32c40ff117fae43913386134c8981539697ce8
    (cherry picked from commit 80e3d9be4923ecad17377b1d15c8392b8a43dac6)

tags: added: in-stable-liberty
Thierry Carrez (ttx)
Changed in neutron:
status: Fix Committed → Fix Released
Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package neutron - 2:7.0.0~rc1-0ubuntu4

---------------
neutron (2:7.0.0~rc1-0ubuntu4) wily; urgency=medium

  * Drop hard requirement on python-ryu for this cycle as it supports
    a new alternative agent implementation for Open vSwitch and is not
    the default, avoiding inclusion of ryu in main for Wily.
    - d/control: Drop (Build-)Depends on ryu, add Suggests.
    - d/p/drop-ryu-dep.patch: Patch out hard requirement on ryu.

 -- James Page <email address hidden> Fri, 02 Oct 2015 18:10:49 +0100

Changed in neutron (Ubuntu):
status: In Progress → Fix Released
tags: added: juno-backport-potential kilo-backport-potential
removed: liberty-rc-potential
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to neutron (stable/kilo)

Fix proposed to branch: stable/kilo
Review: https://review.openstack.org/233136

Revision history for this message
Ihar Hrachyshka (ihar-hrachyshka) wrote :

oslo.log was not used in Juno, so not affected.

tags: removed: juno-backport-potential
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to neutron (stable/kilo)

Reviewed: https://review.openstack.org/233136
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=118a76fd651c19ad098cdee9d0a122a00ddc4e3b
Submitter: Jenkins
Branch: stable/kilo

commit 118a76fd651c19ad098cdee9d0a122a00ddc4e3b
Author: Ihar Hrachyshka <email address hidden>
Date: Thu Oct 1 17:13:25 2015 +0200

    metadata: don't crash proxy on non-unicode user data

    We attempt to log every successful metadata response with LOG.debug. But
    as per oslo.log docs [1], we should make sure that what we pass into the
    library is unicode.

    Http.request returns a tuple of Response object and a string, which is
    bytes in Python 2.x [2].

    That's why we need to convert the response content to unicode before
    passing it into oslo.log.

    To achieve it, we utilize encodeutils.safe_decode with 'replace' errors
    handling strategy, so that we don't get exceptions on input that does
    not conform unicode.

    For the unit test case, we pass a string that is not expected to convert
    to unicode with errors='strict' strategy or similar, and check that we
    still don't crash.

    While at it, we remove a check for the number of log calls being
    triggered, because it's something that we should avoid validating in
    test cases, and it cannot trigger a real bug. The mock that was used to
    count the number would also hide the bug that we try to reproduce.

    Note that the bug does not require debug to be set because the crash
    occurs before oslo.log machinery decides it should not log the message.

    [1]: http://docs.openstack.org/developer/oslo.log/usage.html#no-more-implicit-conversion-to-unicode-str
    [2]: http://bitworking.org/projects/httplib2/doc/html/libhttplib2.html#httplib2.Http.request

    Conflicts:
     neutron/agent/metadata/namespace_proxy.py
     neutron/tests/unit/agent/metadata/test_namespace_proxy.py

    Closes-Bug: #1501772
    Change-Id: I6a32c40ff117fae43913386134c8981539697ce8
    (cherry picked from commit 80e3d9be4923ecad17377b1d15c8392b8a43dac6)

tags: added: in-stable-kilo
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to neutron (stable/juno)

Fix proposed to branch: stable/juno
Review: https://review.openstack.org/233546

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on neutron (stable/juno)

Change abandoned by Ihar Hrachyshka (<email address hidden>) on branch: stable/juno
Review: https://review.openstack.org/233546
Reason: Actually, we don't use oslo.log, neither py34 in Juno, so no need for the change.

Thierry Carrez (ttx)
Changed in neutron:
milestone: liberty-rc2 → 7.0.0
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to neutron (master)

Fix proposed to branch: master
Review: https://review.openstack.org/235300

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to neutron (master)
Download full text (16.6 KiB)

Reviewed: https://review.openstack.org/235300
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=140ccc36d172bead2605968b3d61b36cca8a0040
Submitter: Jenkins
Branch: master

commit 6dcfe3a9362ae5fcf18e5cfb59663e43446cd59c
Author: Kevin Benton <email address hidden>
Date: Tue Oct 6 19:28:47 2015 -0700

    Mock oslo policy HTTPCheck instead of urllib

    We were mocking internal behavior of oslo policy by
    patching urllib. This will break with the upcoming oslo
    release that switches to requests.

    This patch changes the mock to the HTTPCheck level and we
    can leave implementation details testing up to oslo_policy.

    Change-Id: I07957f01307e25f1547197c720eea6e3e7f0ef5a
    Closes-Bug: #1503890
    (cherry picked from commit a0f1d9d6de1560be91d3001c8ac9f880a7a5a7e0)

    Add testresources used by oslo.db fixture

    If we use oslo.db fixtures, we'll need the package or
    the next version of oslo.db release will break us.

    Closes-Bug: #1503501
    Change-Id: I7dfbf240333095d91a414ba15a439bdc4804eb25
    (cherry picked from commit 86ad967e40c2c6752ec0fb46cfd3098ede0c7178)

    Fix functional test_server tests

    Now oslo.service 0.10.0 no longer sends SIGHUP to parent and
    children services.

    This was a chance introduced by 286a6ea, and since it invalidated
    the very logic under test, this must be revised.

    (cherry picked from commit 090fe713592c2b6398d999bfa03b80cbb2054609)

    Change-Id: I18a11283925369bc918002477774f196010a1bc3
    Closes-bug: #1505438
    (cherry picked from commit 090fe713592c2b6398d999bfa03b80cbb2054609)

    Make test_server work with older versions of oslo.service

    Change I18a11283925369bc918002477774f196010a1bc3 fixed the test for
    oslo.service >= 0.10.0, but it also broke it for older versions of
    oslo.service. Since the library has minimal version of >= 0.7.0 in
    requirements.txt, test should pass for those versions too.

    Now, instead of validating that either reset() or restart() of workers
    are triggered on SIGHUP, just validate that .start() is triggered the
    expected number of times (either way, no matter how oslo.service decide
    to clean up the children, they exit and then are respawned).

    Change-Id: I41f9d3af780b3178b075bc1e7084f417a2bd1378
    Closes-Bug: #1505645
    (cherry picked from commit 7bb40921660cf29beb68e338e205499efd6ffa36)

    Fixed multiple py34 gate issues

    1. Scope mock of 'open' to module

    By mocking 'open' at the module level, we can avoid affecting
    'open' calls from other modules.

    2. Stop using LOG.exception in contexts with no sys.exc_info set

    Python 3.4 logger fills in record.exc_info with sys.exc_info() result
    [1], and then it uses it to determine the current exception [2] to
    append to the log message. Since there is no exception, exc_info[1] is
    None, and we get AttributeError inside traceback module.

    It's actually a bug in Python interpreter that it attempt to access the
    attribute when there is no exception. It turns out that it's fixed in
    latest master of cPython [3] (...

Revision history for this message
Thierry Carrez (ttx) wrote : Fix included in openstack/neutron 8.0.0.0b1

This issue was fixed in the openstack/neutron 8.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.