Bug 974940

Summary: Python client unexpected exception after ACL denial
Product: Red Hat Enterprise MRG Reporter: Pavel Moravec <pmoravec>
Component: python-qpidAssignee: Pavel Moravec <pmoravec>
Status: CLOSED ERRATA QA Contact: Zdenek Kraus <zkraus>
Severity: low Docs Contact:
Priority: medium    
Version: 2.3CC: jross, pmoravec, zkraus
Target Milestone: 3.1Keywords: Patch, TestCaseProvided, WorkAround
Target Release: ---   
Hardware: All   
OS: All   
Whiteboard:
Fixed In Version: python-qpid-0.30-2 Doc Type: Bug Fix
Doc Text:
It was discovered that an repeated, unexpected exception was raised by an attempt to manipulate a session with either a (closed) session or (open) connection in Python client, after an execution exception closed the session. The exception handling is now improved in such a way that the exception is cleared after it is raised for the first time. Attempts to close the session or connection no longer re-triggers the exception.
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-04-14 13:46:36 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:
Attachments:
Description Flags
reproducer
none
Simple reproducer
none
Simple patch none

Description Pavel Moravec 2013-06-17 08:10:29 UTC
Description of problem:
After ACL denies a command from qpid Python client, an attempt to close either session or connection raises unexpected exception (relevant to ACL, though). While at that time, session is properly closed and connection is working fine.


Version-Release number of selected component (if applicable):
python-qpid-0.18-4.el6.noarch


How reproducible:
100%


Steps to Reproduce:
1. Have ACL file:
acl deny all consume all
acl allow all all

2. Run attached script.


Actual results:
----------------------------------------------------------------------------------------------------
Create receiver failed with exception
Traceback (most recent call last):
  File "ACL_denial_session-hang.py", line 13, in <module>
    recv = session.receiver('testQ; {create:always}')
  File "<string>", line 6, in receiver
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 616, in receiver
    receiver._ewait(lambda: receiver.linked)
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 973, in _ewait
    result = self.session._ewait(lambda: self.error or predicate(), timeout)
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 567, in _ewait
    self.check_error()
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 556, in check_error
    raise self.error
UnauthorizedAccess: unauthorized-access: ACL denied Queue subscribe request from guest@QPID (qpid/broker/SessionAdapter.cpp:399)(403)
----------------------------------------------------------------------------------------------------
Session close failed with exception
Traceback (most recent call last):
  File "ACL_denial_session-hang.py", line 19, in <module>
    session.close()
  File "<string>", line 6, in close
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 739, in close
    self.sync(timeout=timeout)
  File "<string>", line 6, in sync
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 731, in sync
    if not self._ewait(lambda: not self.outgoing and not self.acked, timeout=timeout):
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 567, in _ewait
    self.check_error()
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 556, in check_error
    raise self.error
UnauthorizedAccess: unauthorized-access: ACL denied Queue subscribe request from guest@QPID (qpid/broker/SessionAdapter.cpp:399)(403)
----------------------------------------------------------------------------------------------------
Connection close failed with exception
Traceback (most recent call last):
  File "ACL_denial_session-hang.py", line 25, in <module>
    connection.close()
  File "<string>", line 6, in close
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 316, in close
    ssn.close(timeout=timeout)
  File "<string>", line 6, in close
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 739, in close
    self.sync(timeout=timeout)
  File "<string>", line 6, in sync
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 731, in sync
    if not self._ewait(lambda: not self.outgoing and not self.acked, timeout=timeout):
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 567, in _ewait
    self.check_error()
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 556, in check_error
    raise self.error
UnauthorizedAccess: unauthorized-access: ACL denied Queue subscribe request from guest@QPID (qpid/broker/SessionAdapter.cpp:399)(403)


Expected results:
Just the first exception is printed - when the "session.receiver" fails due to ACL.


Additional info:
Some hints for fixing it:
- session object is properly closed. Just an attempt to close it again raises that exception. When trying to close a closed session without an ACL deny, no exception is raised
- connection object is properly working and closing it really closes the AMQP connection. And the connection object can be normally used later on.
- it seems to me like:
a) exception raised and stored somewhere
b) program catches it
c) Python library should delete it from the stored place / variable but it does not do so
d) any action on affected session/connection first checks for the stored exception, finds it so re-raises it

Workaround:
try:
        # this should fail - ACL does not allow this
        recv = session.receiver('testQ; {create:always}')
except Exception as e1:
        try:
                session.close()
        except Exception as e2:
                "if e2 is ACL exception, then:"
                        session = connection.session()
                        ..
                "else close connection"

Comment 1 Pavel Moravec 2013-06-17 08:12:36 UTC
Created attachment 761952 [details]
reproducer

Comment 2 Pavel Moravec 2013-06-26 11:34:19 UTC
Created attachment 765524 [details]
Simple reproducer

Two types of changes were required to /usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py:

A) reset session error variable in session.close as it is not further relevant:

@@ -736,6 +736,7 @@ class Session(Endpoint):
     """
     Close the session.
     """
+    self.error = None
     self.sync(timeout=timeout)
 
     for link in self.receivers + self.senders:


B) fixing just the above, the client / reproducer is stuck with traceback:
Traceback (most recent call last):
  File "bz974940.py", line 19, in <module>
    session.close()
  File "<string>", line 6, in close
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 748, in close
    link.close(timeout=timeout)
  File "<string>", line 6, in close
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 1056, in close
    if not self.session._ewait(lambda: self.closed, timeout=timeout):
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 566, in _ewait
    result = self.connection._ewait(lambda: self.error or predicate(), timeout)
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 208, in _ewait
    result = self._wait(lambda: self.error or predicate(), timeout)
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 193, in _wait
    return self._waiter.wait(predicate, timeout=timeout)
  File "/usr/lib/python2.6/site-packages/qpid/concurrency.py", line 57, in wait
    self.condition.wait(3)
  File "/usr/lib/python2.6/site-packages/qpid/concurrency.py", line 96, in wait
    sw.wait(timeout)
  File "/usr/lib/python2.6/site-packages/qpid/compat.py", line 53, in wait
    ready, _, _ = select([self], [], [], timeout)


As receiver on closed session is attempted to be closed. Hence the additional "if not self.session.closed:" added to both Receiver and Sender close methods

Comment 3 Pavel Moravec 2013-06-26 11:35:39 UTC
Created attachment 765525 [details]
Simple patch

Two types of changes were required to /usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py:

A) reset session error variable in session.close as it is not further relevant:

@@ -736,6 +736,7 @@ class Session(Endpoint):
     """
     Close the session.
     """
+    self.error = None
     self.sync(timeout=timeout)
 
     for link in self.receivers + self.senders:


B) fixing just the above, the client / reproducer is stuck with traceback:
Traceback (most recent call last):
  File "bz974940.py", line 19, in <module>
    session.close()
  File "<string>", line 6, in close
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 748, in close
    link.close(timeout=timeout)
  File "<string>", line 6, in close
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 1056, in close
    if not self.session._ewait(lambda: self.closed, timeout=timeout):
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 566, in _ewait
    result = self.connection._ewait(lambda: self.error or predicate(), timeout)
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 208, in _ewait
    result = self._wait(lambda: self.error or predicate(), timeout)
  File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 193, in _wait
    return self._waiter.wait(predicate, timeout=timeout)
  File "/usr/lib/python2.6/site-packages/qpid/concurrency.py", line 57, in wait
    self.condition.wait(3)
  File "/usr/lib/python2.6/site-packages/qpid/concurrency.py", line 96, in wait
    sw.wait(timeout)
  File "/usr/lib/python2.6/site-packages/qpid/compat.py", line 53, in wait
    ready, _, _ = select([self], [], [], timeout)


As receiver on closed session is attempted to be closed. Hence the additional "if not self.session.closed:" added to both Receiver and Sender close methods

Comment 4 Pavel Moravec 2013-06-26 11:36:35 UTC
Resetting devel and 2.4.0 flags as both reproducer & patch is available.

Comment 5 Justin Ross 2013-06-27 14:58:22 UTC
I'd love to accept this, especially since you've done the work for it.  But we're short on QE time, so we'll have to take it for a later release, unless you have some other reason to elevate its priority.

(In reply to Pavel Moravec from comment #4)
> Resetting devel and 2.4.0 flags as both reproducer & patch is available.

Comment 6 Pavel Moravec 2013-10-03 12:56:18 UTC
automated tests found one failing test, see https://reviews.apache.org/r/14466/.

Comment 7 Pavel Moravec 2013-10-23 07:36:27 UTC
Committed upstream in r1534643.

Comment 9 Zdenek Kraus 2015-01-05 10:46:09 UTC
Tested on RHEL 6.6 i686 and x86_64 with following packages:
python-qpid-0.30-2
python-qpid-qmf-0.30-2
qpid-cpp-client-0.30-4
qpid-cpp-client-devel-0.30-4
qpid-cpp-client-devel-docs-0.30-4
qpid-cpp-debuginfo-0.30-4
qpid-cpp-server-0.30-4
qpid-cpp-server-devel-0.30-4
qpid-cpp-server-linearstore-0.30-4
qpid-cpp-server-xml-0.30-4
qpid-java-client-0.30-3
qpid-java-common-0.30-3
qpid-java-example-0.30-3
qpid-jca-0.22-2
qpid-jca-xarecovery-0.22-2
qpid-proton-c-0.8-1
qpid-qmf-0.30-2
qpid-tools-0.30-3


Fix works as expected.
-> VERIFIED

Comment 13 errata-xmlrpc 2015-04-14 13:46:36 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHEA-2015-0805.html