Bug 974676

Description of problem:

Python qpid client rarely refuses to correctly authenticate with qpidd server using GSSAPI [connection-forced: Authentication failed(320) - authentication failure: Requested identity not authenticated identity]:

There are observations that both qpid python clients (low level client, high level client) are rarely failing client-server authentication following way:
Traceback (most recent call last):
  File "/mnt/tests/distribution/MRG/Messaging/qpid_common/clients/python/qc2_spout.py", line 222, in ?
    conn.open()
  File "<string>", line 6, in open
  File "/usr/lib/python2.4/site-packages/qpid/messaging/endpoints.py", line 256, in open
    self.attach()
  File "<string>", line 6, in attach
  File "/usr/lib/python2.4/site-packages/qpid/messaging/endpoints.py", line 274, in attach
    self._ewait(lambda: self._transport_connected and not self._unlinked())
  File "/usr/lib/python2.4/site-packages/qpid/messaging/endpoints.py", line 209, in _ewait
    self.check_error()
  File "/usr/lib/python2.4/site-packages/qpid/messaging/endpoints.py", line 202, in check_error
    raise self.error
qpid.messaging.exceptions.ConnectionError: connection-forced: Authentication failed(320)
ecode:1

broker log appears to show:
2013-06-14 11:17:34 [System] debug RECV [10.16.64.214:35754-10.16.64.214:43388]: INIT(0-10)
2013-06-14 11:17:34 [Security] debug External ssf=0 and auth=
2013-06-14 11:17:34 [Security] debug min_ssf: 0, max_ssf: 256, external_ssf: 0
2013-06-14 11:17:34 [Security] info SASL: Mechanism list: GSSAPI PLAIN LOGIN ANONYMOUS
2013-06-14 11:17:34 [Broker] debug LinkRegistry::notifyConnection(); key=10.16.64.214:35754-10.16.64.214:43388
2013-06-14 11:17:34 [Management] debug Management object (V1) added: org.apache.qpid.broker:connection:10.16.64.214:35754-10.16.64.214:43388
2013-06-14 11:17:34 [Security] info SASL: Starting authentication with mechanism: GSSAPI
2013-06-14 11:17:34 [Security] debug SASL: sending challenge to client
2013-06-14 11:17:34 [Security] debug SASL: sending challenge to client
2013-06-14 11:17:34 [Security] info SASL: Authentication failed for nIK6mBQg47FbeSNt3saqYa2qvI7Xk1KsOvb:SASL(-13): authentication failure: Requested identity not authenticated identity
2013-06-14 11:17:34 [System] debug Exception constructed: Authentication failed
2013-06-14 11:17:34 [Management] debug SEND raiseEvent (v1) class=org.apache.qpid.broker.clientConnectFail
2013-06-14 11:17:34 [Management] debug SEND raiseEvent (v2) class=org.apache.qpid.broker.clientConnectFail
2013-06-14 11:17:34 [Model] debug Failed connection. rhost:10.16.64.214:35754-10.16.64.214:43388 user:nIK6mBQg47FbeSNt3saqYa2qvI7Xk1KsOvb reason:SASL(-13): authentication failure: Requested identity not authenticated identity
2013-06-14 11:17:34 [System] debug DISCONNECTED [10.16.64.214:35754-10.16.64.214:43388]
2013-06-14 11:17:34 [Management] debug SEND raiseEvent (v1) class=org.apache.qpid.broker.clientDisconnect
2013-06-14 11:17:34 [Management] debug SEND raiseEvent (v2) class=org.apache.qpid.broker.clientDisconnect
2013-06-14 11:17:34 [Model] debug Delete connection. user: rhost:10.16.64.214:35754-10.16.64.214:43388

Testing script uses multiple clients in a batch.
Results are showing that just fractional amount of python client authenticating cases are failing.
Just python client is failing, others (c++, ruby, java) are passing.

These facts lead to current conclusion that it is just problem of python client with very low reproducibility.


Version-Release number of selected component (if applicable):
qpid-0.18

How reproducible:
<1%

Steps to Reproduce:
0. perform in loop qpid_ptest_authentication_krb5 test
or following steps   
1. set-up kerberos infrastructure
2. kinit
3. run client[s], expect PASS
4. kdestroy
5. run client[s], expect FAIL
6. kinit
7. run client[s], expect PASS
8. loop steps 2-7.

Actual results:
Python qpid client fails to authenticate using GSSAPI auth. method in situation when success is expected.

Expected results:
Python qpid client should not fail authenticate in above cases.