Bug 546271

Created attachment 377478 [details]
openais/qpidd log files and config files of the experiment

Are you also running "sesame" or another QMF agent service?

There were multiple QMF agens running including sesame and condor's qmf plugins.
I'm going to reproduce once more to prove it was not caused by misconfigured network switch.

Retested once more in the clean cluster environment and seeing the same:

2009-dec-15 05:09:18 debug 192.168.157.10:2366(READY) add local connection 192.168.157.10:2366-7
2009-dec-15 05:09:18 info SASL: Authentication succeeded for: guest@QPID
2009-dec-15 05:09:18 info SASL: Starting authentication with mechanism: PLAIN
2009-dec-15 05:09:18 info SASL: Mechanism list: PLAIN ANONYMOUS LOGIN
2009-dec-15 05:09:18 debug 192.168.157.10:2366(READY) new connection: 192.168.157.10:2366-8(local)
2009-dec-15 05:09:18 debug 192.168.157.10:2366(READY) add local connection 192.168.157.10:2366-8
2009-dec-15 05:09:18 info SASL: Authentication succeeded for: guest@QPID
2009-dec-15 05:09:18 info SASL: Mechanism list: PLAIN ANONYMOUS LOGIN
2009-dec-15 05:09:18 info SASL: Starting authentication with mechanism: PLAIN
2009-dec-15 05:09:18 debug 192.168.157.10:2366(READY) new connection: 192.168.157.10:2366-9(local)
2009-dec-15 05:09:18 debug 192.168.157.10:2366(READY) add local connection 192.168.157.10:2366-9
2009-dec-15 05:09:18 info SASL: Authentication succeeded for: guest@QPID
2009-dec-15 05:09:19 info SASL: Starting authentication with mechanism: PLAIN
2009-dec-15 05:09:19 info SASL: Authentication succeeded for: guest@QPID
2009-dec-15 05:09:19 error Execution exception: resource-locked: Cannot grant exclusive access to queue qmfagent-28b093df-842a-4155-b0eb-f76765daa782 (qpid/broker/SessionAdapter.cpp:392)
2009-dec-15 05:09:19 error 192.168.157.10:2366(READY/error) channel error 105913 on 192.168.157.10:2366-8(local): resource-locked: Cannot grant exclusive access to queue qmfagent-28b093df-842a-4155-b0eb-f76765daa782 (qpid/broker/SessionAdapter.cpp:392) (unresolved: 192.168.157.9:557 192.168.157.10:1999 192.168.157.10:2366 192.168.157.11:6807 192.168.157.11:7138 192.168.157.12:29305 )
2009-dec-15 05:09:19 info 192.168.157.10:2366(READY/error) error 105913 resolved with 192.168.157.10:2366
2009-dec-15 05:09:19 info 192.168.157.10:2366(READY/error) error 105913 must be resolved with 192.168.157.9:557 192.168.157.10:1999 192.168.157.11:6807 192.168.157.11:7138 192.168.157.12:29305
2009-dec-15 05:09:19 critical 192.168.157.10:2366(READY/error) error 105913 did not occur on 192.168.157.9:937
2009-dec-15 05:09:19 error Error delivering frames: Error 105913 did not occur on all members (qpid/cluster/ErrorCheck.cpp:90)
2009-dec-15 05:09:19 notice 192.168.157.10:2366(LEFT/error) leaving cluster mrg_pepe_test_cluster
2009-dec-15 05:09:19 debug 192.168.157.10:2366(LEFT/error) deleted connection: 192.168.157.10:1999-6(shadow)
2009-dec-15 05:09:19 debug 192.168.157.10:2366(LEFT/error) deleted connection: 192.168.157.10:1999-5(shadow)
2009-dec-15 05:09:19 debug 192.168.157.10:2366(LEFT/error) deleted connection: 192.168.157.10:1999-4(shadow)
2009-dec-15 05:09:19 debug 192.168.157.10:2366(LEFT/error) deleted connection: 192.168.157.10:1999-3(shadow)
2009-dec-15 05:09:19 debug Shutting down CPG
2009-dec-15 05:09:19 notice Shut down


Summary:
I believe there is the issue on 1.2 packages.

qpidd daemon run together with sesame and condor qmf daemons.


root@mrg-qe-10:~# cat /etc/qpidd.conf

cluster-mechanism=ANONYMOUS
#max-session-rate=10000
cluster-name=mrg_pepe_test_cluster
cluster-cman=no
auth=yes
log-enable=info+
log-enable=debug+:cluster
log-to-file=/tmp/qpidd.log

root@mrg-qe-10:~# cat `rpm -qlc sesame`
##
##  sesame configuration
##

##===================
## Broker Connection
##===================

##
## Set the host and port of the broker that this agent shall attempt to
## connect to.  The port will default to the appropriate value based on the
## protocol.
##
##  For proto=tcp, the default port is 5672
##      proto=ssl,  5671
##      proto=rdma, 5672
##
host=localhost
proto=tcp
port=5672

##======================
## Agent Authentication
##======================

##
## Set the SASL mechanism (PLAIN by default), and the username and password
## to be used when authenticating to the broker.  If you wish to not store
## the password in this configuration file, you may use pwd-file to point
## to an access-restricted file containing the password.
##
mech=PLAIN
uid=guest
pwd=guest
#pwd-file=/etc/sesame/password

##==============
## Data Storage
##==============

##
## Set the path to the directory where sesame will store persistent data.
##
#state-dir=/var/lib/sesame

##=========
## Logging
##=========

#  log-enable=RULE
#
#  Enable logging for selected levels and components. RULE is in the form
#  'LEVEL[+][:PATTERN]' Levels are one of:
#        trace debug info notice warning error critical
#
#  For example:
#     '--log-enable warning+' logs all warning, error and critical messages.

#log-enable notice+

root@mrg-qe-10:~# cat ~condor/condor_config.local
CONDOR_HOST = $(FULL_HOSTNAME)
QMF_BROKER_HOST = 192.168.157.10
COLLECTOR_NAME = Brno MRG Condor Pool
START = TRUE
SUSPEND = FALSE
PREEMPT = FALSE
KILL = FALSE
DAEMON_LIST = COLLECTOR, MASTER, NEGOTIATOR, SCHEDD, STARTD
NEGOTIATOR_INTERVAL = 20
TRUST_UID_DOMAIN = TRUE
CONDOR_DEVELOPERS = NONE

HOSTALLOW_WRITE = *
HOSTALLOW_READ = *

SCHEDD.PLUGINS = $(LIB)/plugins/MgmtScheddPlugin-plugin.so
COLLECTOR.PLUGINS = $(LIB)/plugins/MgmtCollectorPlugin-plugin.so
NEGOTIATOR.PLUGINS = $(LIB)/plugins/MgmtNegotiatorPlugin-plugin.so
MASTER.PLUGINS = $(LIB)/plugins/MgmtMasterPlugin-plugin.so

Everything else is default.

Having trouble reproducing this. Can you confirm these steps:

1. run this loop on all hosts continuously: 
  while true; do qpid-cluster;qpid-stat -b;qpid-config queues; done
2. Start openais and qpidd on all hosts.
3. Do service qpidd restart  while client loop is running
 - is this run individually on each host, or repeatedly on one host?

The repro steps were:
0. Stop all MRG daemons (condor, sesame, qpidd+openais)
1. configure the daemons as described above (openais.conf, qpidd.conf, ~condor/condor_config.local)
2. start condor and sesame daemons
3. start openais daemon
4. start qpidd daemon
5. Run the loop
while true; do qpid-cluster;qpid-stat -b;qpid-config queues; netstat -nlp |
grep qpidd;done

-> there are running above listed daemons + point 5. loop on every cluster node / separate machine


The above described failure appears just after cluster node start-up, so it is visible in the point 5. loop log. You may need to re-start qpidd (and just qpidd, not the others) multiple-times to see this behavior (in my case it was more than 5 times (restarting just all nodes one after each other))

In the logs attached above first one (mrg-qe-09) and last one (4th one, mrg-qe-12) brokers left cluster because of 
"resource-locked: Cannot grant exclusive access to queue  qmfagent-..."
exception the other two were not affected.

I believe the key is that qpidd+openais together with qmf configured condor and sesame are running.

Let me know if it helps, I may find time to prepare this case on mrg-qe-09...12 for you.

Hi Alan,
I'm currently trying to reproduce on the same machines.
I created semi-automated reproducer, but still tuning and no luck.
I'll keep you updated.

I spent enormous effort to reproduce the issue, but without the luck of triggering the issue.

There has to be either special timing involved or I was doing something wrong...


-> CLOSED (INSUFFICIENT DATA)


There might be dependency on bug 558526. Once bug 558526 fixed, this bug will be retested and reopened if issue triggered.