Bug 507363

[root@mrg-qe-01 ~]# ifconfig eth0
eth0      Link encap:Ethernet  HWaddr 00:22:19:2E:F6:04
          inet addr:10.34.33.54  Bcast:10.34.35.255  Mask:255.255.252.0
          inet6 addr: fec0::f101:222:19ff:fe2e:f604/64 Scope:Site
          inet6 addr: fe80::222:19ff:fe2e:f604/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:3620288 errors:0 dropped:17 overruns:0 frame:0
          TX packets:3271437 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:1328343658 (1.2 GiB)  TX bytes:487099057 (464.5 MiB)
          Interrupt:177
[root@mrg-qe-01 ~]# cat /etc/ais/openais.conf
# Please read the openais.conf.5 manual page

totem {
        version: 2
        secauth: off
        threads: 0
        interface {
                ringnumber: 0
bindnetaddr: 10.34.32.0
                mcastaddr: 226.94.1.11
                mcastport: 54015
        }
}

logging {
debug: on
timestamp: on
to_file: yes
logfile: /root/qpid_ptest_cluster_failover_soak/openais.log
}

amf {
        mode: disabled
}


[root@mrg-qe-01 ~]# vi /etc/ais/openais.conf
[root@mrg-qe-01 ~]# mv /root/qpid_ptest_cluster_failover_soak/openais.log /root/qpid_ptest_cluster_failover_soak/openais.log__
[root@mrg-qe-01 ~]# service openais restart
Stopping OpenAIS daemon (aisexec):                         [  OK  ]
Starting OpenAIS daemon (aisexec):                         [  OK  ]
[1]+  Exit 1                  qpidd -t --auth no -p 5677 --cluster-name ASy --data-dir y > qpidd.log 2>&1
[root@mrg-qe-01 ~]# geten
getenforce  getent
[root@mrg-qe-01 ~]# getenforce
Permissive
[root@mrg-qe-01 ~]# setenforce 0
[root@mrg-qe-01 ~]# getenforce
Permissive
[root@mrg-qe-01 ~]# ps auxw |grep qpid
root     16326  0.0  0.0   3912   680 pts/1    S+   13:12   0:00 grep qpid
[root@mrg-qe-01 ~]# rm -rf y
[root@mrg-qe-01 ~]# rm -rf *.log
[root@mrg-qe-01 ~]# qpidd -t --auth no -p 15677 --cluster-name ASy --data-dir y > qpidd.log 2>&1

[1]+  Stopped                 qpidd -t --auth no -p 15677 --cluster-name ASy --data-dir y > qpidd.log 2>&1
[root@mrg-qe-01 ~]# bg
[1]+ qpidd -t --auth no -p 15677 --cluster-name ASy --data-dir y > qpidd.log 2>&1 &
[root@mrg-qe-01 ~]# tail qpidd.log
2009-jun-23 13:13:08 info > Default journal file size: 24 (wpgs)
2009-jun-23 13:13:08 info > Default write cache page size: 32 (Kib)
2009-jun-23 13:13:08 info > Default number of write cache pages: 32
2009-jun-23 13:13:08 info > TPL files per journal: 8
2009-jun-23 13:13:08 info > TPL journal file size: 24 (wpgs)
2009-jun-23 13:13:08 info > TPL write cache page size: 4 (Kib)
2009-jun-23 13:13:08 info > TPL number of write cache pages: 64
2009-jun-23 13:13:08 info Initializing CPG
2009-jun-23 13:13:08 debug ManagementBroker added package org.apache.qpid.cluster
2009-jun-23 13:13:08 debug ManagementBroker added class org.apache.qpid.cluster:cluster
[root@mrg-qe-01 ~]# ps auxw |grep qpid
root     16331  0.3  0.1  68092  9768 pts/1    Sl   13:13   0:00 qpidd -t --auth no -p 15677 --cluster-name ASy --data-dir y
root     16339  0.0  0.0   3912   684 pts/1    S+   13:13   0:00 grep qpid
[root@mrg-qe-01 ~]# netstat -nlp | grep qpidd
[root@mrg-qe-01 ~]# rpm -q openais
openais-0.80.3-22.el5_3.8
[root@mrg-qe-01 ~]# rpm -qa | grep openais
openais-0.80.3-22.el5_3.8
openais-debuginfo-0.80.3-22.el5_3.8
[root@mrg-qe-01 ~]# ps auxw | grep aisexec
root     16304  0.0  0.2  18512 17484 pts/1    SLl  13:10   0:00 /usr/sbin/aisexec
root     16348  0.0  0.0   3912   684 pts/1    S+   13:14   0:00 grep aisexec
[root@mrg-qe-01 ~]# pstack 16304
Thread 4 (Thread 0xb7f70230 (LWP 16305)):
#0  0x006c1410 in __kernel_vsyscall ()
#1  0x005cb973 in poll () from /lib/libc.so.6
#2  0x0806653e in ?? ()
#3  0x0067e49b in start_thread () from /lib/libpthread.so.0
#4  0x005d542e in clone () from /lib/libc.so.6
Thread 3 (Thread 0xb7f57b90 (LWP 16307)):
#0  0x006c1410 in __kernel_vsyscall ()
#1  0x00682595 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x080612ae in worker_thread ()
#3  0x0067e49b in start_thread () from /lib/libpthread.so.0
#4  0x005d542e in clone () from /lib/libc.so.6
Thread 2 (Thread 0xb74f38d0 (LWP 16336)):
#0  0x006c1410 in __kernel_vsyscall ()
#1  0x005d6ceb in semop () from /lib/libc.so.6
#2  0x0806508c in ?? ()
#3  0x0067e49b in start_thread () from /lib/libpthread.so.0
#4  0x005d542e in clone () from /lib/libc.so.6
Thread 1 (Thread 0xb7f716c0 (LWP 16304)):
#0  0x006c1410 in __kernel_vsyscall ()
#1  0x005cb973 in poll () from /lib/libc.so.6
#2  0x0804c5f7 in poll_run ()
#3  0x08061f28 in main ()
[root@mrg-qe-01 ~]# gdb
GNU gdb Fedora (6.8-27.el5)
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "i386-redhat-linux-gnu".
(gdb) attach 16304
Attaching to process 16304
Reading symbols from /usr/sbin/aisexec...Reading symbols from /usr/lib/debug/usr/sbin/aisexec.debug...done.
done.
Reading symbols from /lib/libdl.so.2...done.
Loaded symbols for /lib/libdl.so.2
Reading symbols from /lib/libpthread.so.0...done.
[Thread debugging using libthread_db enabled]
[New Thread 0xb7f716c0 (LWP 16304)]
[New Thread 0xb74f38d0 (LWP 16336)]
[New Thread 0xb7f57b90 (LWP 16307)]
[New Thread 0xb7f70230 (LWP 16305)]
Loaded symbols for /lib/libpthread.so.0
Reading symbols from /lib/libc.so.6...done.
Loaded symbols for /lib/libc.so.6
Reading symbols from /lib/ld-linux.so.2...done.
Loaded symbols for /lib/ld-linux.so.2
Reading symbols from /usr/libexec/lcrso/objdb.lcrso...Reading symbols from /usr/lib/debug/usr/libexec/lcrso/objdb.lcrso.debug...done.
done.
Loaded symbols for /usr/libexec/lcrso/objdb.lcrso
Reading symbols from /usr/libexec/lcrso/aisparser.lcrso...Reading symbols from /usr/lib/debug/usr/libexec/lcrso/aisparser.lcrso.debug...done.
done.
Loaded symbols for /usr/libexec/lcrso/aisparser.lcrso
Reading symbols from /usr/libexec/lcrso/service_cpg.lcrso...Reading symbols from /usr/lib/debug/usr/libexec/lcrso/service_cpg.lcrso.debug...done.
done.
Loaded symbols for /usr/libexec/lcrso/service_cpg.lcrso
Reading symbols from /usr/libexec/lcrso/service_cfg.lcrso...Reading symbols from /usr/lib/debug/usr/libexec/lcrso/service_cfg.lcrso.debug...done.
done.
Loaded symbols for /usr/libexec/lcrso/service_cfg.lcrso
Reading symbols from /usr/libexec/lcrso/service_msg.lcrso...Reading symbols from /usr/lib/debug/usr/libexec/lcrso/service_msg.lcrso.debug...done.
done.
Loaded symbols for /usr/libexec/lcrso/service_msg.lcrso
Reading symbols from /usr/libexec/lcrso/service_lck.lcrso...Reading symbols from /usr/lib/debug/usr/libexec/lcrso/service_lck.lcrso.debug...done.
done.
Loaded symbols for /usr/libexec/lcrso/service_lck.lcrso
Reading symbols from /usr/libexec/lcrso/service_evt.lcrso...Reading symbols from /usr/lib/debug/usr/libexec/lcrso/service_evt.lcrso.debug...done.
done.
Loaded symbols for /usr/libexec/lcrso/service_evt.lcrso
Reading symbols from /usr/libexec/lcrso/service_ckpt.lcrso...Reading symbols from /usr/lib/debug/usr/libexec/lcrso/service_ckpt.lcrso.debug...done.
done.
Loaded symbols for /usr/libexec/lcrso/service_ckpt.lcrso
Reading symbols from /usr/libexec/lcrso/service_amf.lcrso...Reading symbols from /usr/lib/debug/usr/libexec/lcrso/service_amf.lcrso.debug...done.
done.
Loaded symbols for /usr/libexec/lcrso/service_amf.lcrso
Reading symbols from /usr/libexec/lcrso/service_clm.lcrso...Reading symbols from /usr/lib/debug/usr/libexec/lcrso/service_clm.lcrso.debug...done.
done.
Loaded symbols for /usr/libexec/lcrso/service_clm.lcrso
Reading symbols from /usr/libexec/lcrso/service_evs.lcrso...Reading symbols from /usr/lib/debug/usr/libexec/lcrso/service_evs.lcrso.debug...done.
done.
Loaded symbols for /usr/libexec/lcrso/service_evs.lcrso
Reading symbols from /lib/libnss_files.so.2...done.
Loaded symbols for /lib/libnss_files.so.2
0x006c1410 in __kernel_vsyscall ()
(gdb) info threads
  4 Thread 0xb7f70230 (LWP 16305)  0x006c1410 in __kernel_vsyscall ()
  3 Thread 0xb7f57b90 (LWP 16307)  0x006c1410 in __kernel_vsyscall ()
  2 Thread 0xb74f38d0 (LWP 16336)  0x006c1410 in __kernel_vsyscall ()
* 1 Thread 0xb7f716c0 (LWP 16304)  0x006c1410 in __kernel_vsyscall ()
(gdb) thread apply all bt

Thread 4 (Thread 0xb7f70230 (LWP 16305)):
#0  0x006c1410 in __kernel_vsyscall ()
#1  0x005cb973 in poll () from /lib/libc.so.6
#2  0x0806653e in prioritized_timer_thread (data=0x0) at timer.c:125
#3  0x0067e49b in start_thread () from /lib/libpthread.so.0
#4  0x005d542e in clone () from /lib/libc.so.6

Thread 3 (Thread 0xb7f57b90 (LWP 16307)):
#0  0x006c1410 in __kernel_vsyscall ()
#1  0x00682595 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x080612ae in worker_thread (thread_data_in=0x94a4cc4) at wthread.c:73
#3  0x0067e49b in start_thread () from /lib/libpthread.so.0
#4  0x005d542e in clone () from /lib/libc.so.6

Thread 2 (Thread 0xb74f38d0 (LWP 16336)):
#0  0x006c1410 in __kernel_vsyscall ()
#1  0x005d6ceb in semop () from /lib/libc.so.6
#2  0x0806508c in pthread_ipc_consumer (conn=0x0) at ipc.c:289
#3  0x0067e49b in start_thread () from /lib/libpthread.so.0
#4  0x005d542e in clone () from /lib/libc.so.6

Thread 1 (Thread 0xb7f716c0 (LWP 16304)):
#0  0x006c1410 in __kernel_vsyscall ()
#1  0x005cb973 in poll () from /lib/libc.so.6
#2  0x0804c5f7 in poll_run (handle=0) at aispoll.c:384
#3  0x08061f28 in main (argc=Cannot access memory at address 0x4
) at main.c:609
(gdb)

Thread 4 (Thread 0xb7f70230 (LWP 16305)):
#0  0x006c1410 in __kernel_vsyscall ()
#1  0x005cb973 in poll () from /lib/libc.so.6
#2  0x0806653e in prioritized_timer_thread (data=0x0) at timer.c:125
#3  0x0067e49b in start_thread () from /lib/libpthread.so.0
#4  0x005d542e in clone () from /lib/libc.so.6

Thread 3 (Thread 0xb7f57b90 (LWP 16307)):
#0  0x006c1410 in __kernel_vsyscall ()
#1  0x00682595 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x080612ae in worker_thread (thread_data_in=0x94a4cc4) at wthread.c:73
#3  0x0067e49b in start_thread () from /lib/libpthread.so.0
#4  0x005d542e in clone () from /lib/libc.so.6

Thread 2 (Thread 0xb74f38d0 (LWP 16336)):
#0  0x006c1410 in __kernel_vsyscall ()
#1  0x005d6ceb in semop () from /lib/libc.so.6
#2  0x0806508c in pthread_ipc_consumer (conn=0x0) at ipc.c:289
#3  0x0067e49b in start_thread () from /lib/libpthread.so.0
#4  0x005d542e in clone () from /lib/libc.so.6

Thread 1 (Thread 0xb7f716c0 (LWP 16304)):
#0  0x006c1410 in __kernel_vsyscall ()
#1  0x005cb973 in poll () from /lib/libc.so.6
#2  0x0804c5f7 in poll_run (handle=0) at aispoll.c:384
#3  0x08061f28 in main (argc=Cannot access memory at address 0x4
) at main.c:609
(gdb) quit
The program is running.  Quit anyway (and detach it)? (y or n) y
Detaching from program: /usr/sbin/aisexec, process 16304
[root@mrg-qe-01 ~]# pstack 16304
Thread 4 (Thread 0xb7f70230 (LWP 16305)):
#0  0x006c1410 in __kernel_vsyscall ()
#1  0x005cb973 in poll () from /lib/libc.so.6
#2  0x0806653e in ?? ()
#3  0x0067e49b in start_thread () from /lib/libpthread.so.0
#4  0x005d542e in clone () from /lib/libc.so.6
Thread 3 (Thread 0xb7f57b90 (LWP 16307)):
#0  0x006c1410 in __kernel_vsyscall ()
#1  0x00682595 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x080612ae in worker_thread ()
#3  0x0067e49b in start_thread () from /lib/libpthread.so.0
#4  0x005d542e in clone () from /lib/libc.so.6
Thread 2 (Thread 0xb74f38d0 (LWP 16336)):
#0  0x006c1410 in __kernel_vsyscall ()
#1  0x005d6ceb in semop () from /lib/libc.so.6
#2  0x0806508c in ?? ()
#3  0x0067e49b in start_thread () from /lib/libpthread.so.0
#4  0x005d542e in clone () from /lib/libc.so.6
Thread 1 (Thread 0xb7f716c0 (LWP 16304)):
#0  0x006c1410 in __kernel_vsyscall ()
#1  0x005cb973 in poll () from /lib/libc.so.6
#2  0x0804c5f7 in poll_run ()
#3  0x08061f28 in main ()

[root@mrg-qe-01 ~]# pstack 16331
Thread 5 (Thread 0xb7f37b90 (LWP 16332)):
#0  0x009ac410 in __kernel_vsyscall ()
#1  0x006828c2 in pthread_cond_timedwait@@GLIBC_2.3.2 ()
#2  0x005e1b84 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libc.so.6
#3  0x00dd8b1e in qpid::broker::Timer::run () from /usr/lib/libqpidbroker.so.0
#4  0x00251581 in ?? () from /usr/lib/libqpidcommon.so.0
#5  0x0067e49b in start_thread () from /lib/libpthread.so.0
#6  0x005d542e in clone () from /lib/libc.so.6
Thread 4 (Thread 0xb7536b90 (LWP 16333)):
#0  0x009ac410 in __kernel_vsyscall ()
#1  0x006828c2 in pthread_cond_timedwait@@GLIBC_2.3.2 ()
#2  0x005e1b84 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libc.so.6
#3  0x00dd8b1e in qpid::broker::Timer::run () from /usr/lib/libqpidbroker.so.0
#4  0x00251581 in ?? () from /usr/lib/libqpidcommon.so.0
#5  0x0067e49b in start_thread () from /lib/libpthread.so.0
#6  0x005d542e in clone () from /lib/libc.so.6
Thread 3 (Thread 0xb6b35b90 (LWP 16334)):
#0  0x009ac410 in __kernel_vsyscall ()
#1  0x00682595 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x005e1b3d in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libc.so.6
#3  0x00dd8907 in qpid::broker::Timer::run () from /usr/lib/libqpidbroker.so.0
#4  0x00251581 in ?? () from /usr/lib/libqpidcommon.so.0
#5  0x0067e49b in start_thread () from /lib/libpthread.so.0
#6  0x005d542e in clone () from /lib/libc.so.6
Thread 2 (Thread 0xb603ab90 (LWP 16335)):
#0  0x009ac410 in __kernel_vsyscall ()
#1  0x006828c2 in pthread_cond_timedwait@@GLIBC_2.3.2 ()
#2  0x005e1b84 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libc.so.6
#3  0x00dd8b1e in qpid::broker::Timer::run () from /usr/lib/libqpidbroker.so.0
#4  0x00251581 in ?? () from /usr/lib/libqpidcommon.so.0
#5  0x0067e49b in start_thread () from /lib/libpthread.so.0
#6  0x005d542e in clone () from /lib/libc.so.6
Thread 1 (Thread 0xb7f69720 (LWP 16331)):
#0  0x009ac410 in __kernel_vsyscall ()
#1  0x005cb973 in poll () from /lib/libc.so.6
#2  0x004957e6 in openais_dispatch_recv () from /usr/lib/openais/libcpg.so.2
#3  0x004968c3 in cpg_dispatch () from /usr/lib/openais/libcpg.so.2
#4  0x00860db3 in qpid::cluster::Cpg::dispatchOne ()
#5  0x00834b4f in qpid::cluster::Cluster::Cluster ()
#6  0x008521cc in qpid::cluster::ClusterPlugin::earlyInitialize ()
#7  0x00d01684 in qpid::broker::Broker::Broker ()
#8  0x0804dcc0 in ?? ()
#9  0x0804c6c7 in __cxa_pure_virtual ()
#10 0x00519e8c in __libc_start_main () from /lib/libc.so.6
#11 0x0804c051 in __cxa_pure_virtual ()
[root@mrg-qe-01 ~]# gdb
GNU gdb Fedora (6.8-27.el5)
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "i386-redhat-linux-gnu".
(gdb) attach 16331
Attaching to process 16331
Reading symbols from /usr/sbin/qpidd...warning: the debug information found in "/usr/lib/debug//usr/sbin/qpidd.debug" does not match "/usr/sbin/qpidd" (CRC mismatch).

warning: the debug information found in "/usr/lib/debug/usr/sbin/qpidd.debug" does not match "/usr/sbin/qpidd" (CRC mismatch).

(no debugging symbols found)...done.
Reading symbols from /usr/lib/libqpidbroker.so.0...warning: the debug information found in "/usr/lib/debug//usr/lib/libqpidbroker.so.0.1.0.debug" does not match "/usr/lib/libqpidbroker.so.0" (CRC mismatch).

warning: the debug information found in "/usr/lib/debug/usr/lib/libqpidbroker.so.0.1.0.debug" does not match "/usr/lib/libqpidbroker.so.0" (CRC mismatch).

(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libqpidbroker.so.0
Reading symbols from /usr/lib/libqpidcommon.so.0...warning: the debug information found in "/usr/lib/debug//usr/lib/libqpidcommon.so.0.1.0.debug" does not match "/usr/lib/libqpidcommon.so.0" (CRC mismatch).

warning: the debug information found in "/usr/lib/debug/usr/lib/libqpidcommon.so.0.1.0.debug" does not match "/usr/lib/libqpidcommon.so.0" (CRC mismatch).

(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libqpidcommon.so.0
Reading symbols from /usr/lib/libboost_program_options.so.2...(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libboost_program_options.so.2
Reading symbols from /usr/lib/libboost_filesystem.so.2...
(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libboost_filesystem.so.2
Reading symbols from /lib/libuuid.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib/libuuid.so.1
Reading symbols from /lib/libdl.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib/libdl.so.2
Reading symbols from /lib/librt.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib/librt.so.1
Reading symbols from /usr/lib/libsasl2.so.2...
(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libsasl2.so.2
Reading symbols from /usr/lib/libstdc++.so.6...(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libstdc++.so.6
Reading symbols from /lib/libm.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib/libm.so.6
Reading symbols from /lib/libgcc_s.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib/libgcc_s.so.1
Reading symbols from /lib/libc.so.6...
(no debugging symbols found)...done.
Loaded symbols for /lib/libc.so.6
Reading symbols from /lib/ld-linux.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib/ld-linux.so.2
Reading symbols from /lib/libpthread.so.0...(no debugging symbols found)...done.
[Thread debugging using libthread_db enabled]
[New Thread 0xb7f69720 (LWP 16331)]
[New Thread 0xb603ab90 (LWP 16335)]
[New Thread 0xb6b35b90 (LWP 16334)]
[New Thread 0xb7536b90 (LWP 16333)]
[New Thread 0xb7f37b90 (LWP 16332)]
Loaded symbols for /lib/libpthread.so.0
Reading symbols from /lib/libresolv.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib/libresolv.so.2
Reading symbols from /lib/libcrypt.so.1...
(no debugging symbols found)...done.
Loaded symbols for /lib/libcrypt.so.1
Reading symbols from /usr/lib/qpid/daemon/acl.so...warning: the debug information found in "/usr/lib/debug//usr/lib/qpid/daemon/acl.so.debug" does not match "/usr/lib/qpid/daemon/acl.so" (CRC mismatch).

warning: the debug information found in "/usr/lib/debug/usr/lib/qpid/daemon/acl.so.debug" does not match "/usr/lib/qpid/daemon/acl.so" (CRC mismatch).

(no debugging symbols found)...done.
Loaded symbols for /usr/lib/qpid/daemon/acl.so
Reading symbols from /usr/lib/qpid/daemon/ssl.so...warning: the debug information found in "/usr/lib/debug//usr/lib/qpid/daemon/ssl.so.debug" does not match "/usr/lib/qpid/daemon/ssl.so" (CRC mismatch).

warning: the debug information found in "/usr/lib/debug/usr/lib/qpid/daemon/ssl.so.debug" does not match "/usr/lib/qpid/daemon/ssl.so" (CRC mismatch).

(no debugging symbols found)...done.
Loaded symbols for /usr/lib/qpid/daemon/ssl.so
Reading symbols from /usr/lib/libsslcommon.so.0...warning: the debug information found in "/usr/lib/debug//usr/lib/libsslcommon.so.0.1.0.debug" does not match "/usr/lib/libsslcommon.so.0" (CRC mismatch).

warning: the debug information found in "/usr/lib/debug/usr/lib/libsslcommon.so.0.1.0.debug" does not match "/usr/lib/libsslcommon.so.0" (CRC mismatch).

(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libsslcommon.so.0
Reading symbols from /usr/lib/libnss3.so...
(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libnss3.so
Reading symbols from /usr/lib/libssl3.so...(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libssl3.so
Reading symbols from /usr/lib/libnspr4.so...(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libnspr4.so
Reading symbols from /usr/lib/libnssutil3.so...(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libnssutil3.so
Reading symbols from /usr/lib/libplc4.so...
(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libplc4.so
Reading symbols from /usr/lib/libplds4.so...(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libplds4.so
Reading symbols from /usr/lib/qpid/daemon/replicating_listener.so...warning: the debug information found in "/usr/lib/debug//usr/lib/qpid/daemon/replicating_listener.so.debug" does not match "/usr/lib/qpid/daemon/replicating_listener.so" (CRC mismatch).

warning: the debug information found in "/usr/lib/debug/usr/lib/qpid/daemon/replicating_listener.so.debug" does not match "/usr/lib/qpid/daemon/replicating_listener.so" (CRC mismatch).

(no debugging symbols found)...done.
Loaded symbols for /usr/lib/qpid/daemon/replicating_listener.so
Reading symbols from /usr/lib/qpid/daemon/msgstore.so...(no debugging symbols found)...done.
Loaded symbols for /usr/lib/qpid/daemon/msgstore.so
Reading symbols from /usr/lib/libdb_cxx-4.3.so...
(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libdb_cxx-4.3.so
Reading symbols from /usr/lib/libaio.so.1...(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libaio.so.1
Reading symbols from /usr/lib/qpid/daemon/rdma.so...warning: the debug information found in "/usr/lib/debug//usr/lib/qpid/daemon/rdma.so.debug" does not match "/usr/lib/qpid/daemon/rdma.so" (CRC mismatch).

warning: the debug information found in "/usr/lib/debug/usr/lib/qpid/daemon/rdma.so.debug" does not match "/usr/lib/qpid/daemon/rdma.so" (CRC mismatch).

(no debugging symbols found)...done.
Loaded symbols for /usr/lib/qpid/daemon/rdma.so
Reading symbols from /usr/lib/librdmawrap.so.0...warning: the debug information found in "/usr/lib/debug//usr/lib/librdmawrap.so.0.1.0.debug" does not match "/usr/lib/librdmawrap.so.0" (CRC mismatch).

warning: the debug information found in "/usr/lib/debug/usr/lib/librdmawrap.so.0.1.0.debug" does not match "/usr/lib/librdmawrap.so.0" (CRC mismatch).

(no debugging symbols found)...done.
Loaded symbols for /usr/lib/librdmawrap.so.0
Reading symbols from /usr/lib/librdmacm.so.1...
(no debugging symbols found)...done.
Loaded symbols for /usr/lib/librdmacm.so.1
Reading symbols from /usr/lib/libibverbs.so.1...(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libibverbs.so.1
Reading symbols from /usr/lib/qpid/daemon/replication_exchange.so...warning: the debug information found in "/usr/lib/debug//usr/lib/qpid/daemon/replication_exchange.so.debug" does not match "/usr/lib/qpid/daemon/replication_exchange.so" (CRC mismatch).

warning: the debug information found in "/usr/lib/debug/usr/lib/qpid/daemon/replication_exchange.so.debug" does not match "/usr/lib/qpid/daemon/replication_exchange.so" (CRC mismatch).

(no debugging symbols found)...done.
Loaded symbols for /usr/lib/qpid/daemon/replication_exchange.so
Reading symbols from /usr/lib/qpid/daemon/cluster.so...warning: the debug information found in "/usr/lib/debug//usr/lib/qpid/daemon/cluster.so.debug" does not match "/usr/lib/qpid/daemon/cluster.so" (CRC mismatch).

warning: the debug information found in "/usr/lib/debug/usr/lib/qpid/daemon/cluster.so.debug" does not match "/usr/lib/qpid/daemon/cluster.so" (CRC mismatch).

(no debugging symbols found)...done.
Loaded symbols for /usr/lib/qpid/daemon/cluster.so
Reading symbols from /usr/lib/openais/libcpg.so.2...Reading symbols from /usr/lib/debug/usr/lib/openais/libcpg.so.2.0.0.debug...done.
done.
Loaded symbols for /usr/lib/openais/libcpg.so.2
Reading symbols from /usr/lib/libcman.so.2...done.
Loaded symbols for /usr/lib/libcman.so.2
Reading symbols from /usr/lib/libqpidclient.so.0...warning: the debug information found in "/usr/lib/debug//usr/lib/libqpidclient.so.0.1.0.debug" does not match "/usr/lib/libqpidclient.so.0" (CRC mismatch).

warning: the debug information found in "/usr/lib/debug/usr/lib/libqpidclient.so.0.1.0.debug" does not match "/usr/lib/libqpidclient.so.0" (CRC mismatch).

done.
Loaded symbols for /usr/lib/libqpidclient.so.0
Reading symbols from /usr/lib/qpid/client/sslconnector.so...warning: the debug information found in "/usr/lib/debug//usr/lib/qpid/client/sslconnector.so.debug" does not match "/usr/lib/qpid/client/sslconnector.so" (CRC mismatch).

warning: the debug information found in "/usr/lib/debug/usr/lib/qpid/client/sslconnector.so.debug" does not match "/usr/lib/qpid/client/sslconnector.so" (CRC mismatch).

done.
Loaded symbols for /usr/lib/qpid/client/sslconnector.so
Reading symbols from /usr/lib/qpid/client/rdmaconnector.so...warning: the debug information found in "/usr/lib/debug//usr/lib/qpid/client/rdmaconnector.so.debug" does not match "/usr/lib/qpid/client/rdmaconnector.so" (CRC mismatch).

warning: the debug information found in "/usr/lib/debug/usr/lib/qpid/client/rdmaconnector.so.debug" does not match "/usr/lib/qpid/client/rdmaconnector.so" (CRC mismatch).

done.
Loaded symbols for /usr/lib/qpid/client/rdmaconnector.so
Reading symbols from /usr/lib/qpid/daemon/xml.so...warning: the debug information found in "/usr/lib/debug//usr/lib/qpid/daemon/xml.so.debug" does not match "/usr/lib/qpid/daemon/xml.so" (CRC mismatch).

warning: the debug information found in "/usr/lib/debug/usr/lib/qpid/daemon/xml.so.debug" does not match "/usr/lib/qpid/daemon/xml.so" (CRC mismatch).

done.
Loaded symbols for /usr/lib/qpid/daemon/xml.so
Reading symbols from /usr/lib/libxerces-c.so.28...done.
Loaded symbols for /usr/lib/libxerces-c.so.28
Reading symbols from /usr/lib/libxqilla.so.3...done.
Loaded symbols for /usr/lib/libxqilla.so.3

0x009ac410 in __kernel_vsyscall ()
(gdb) info threads
  5 Thread 0xb7f37b90 (LWP 16332)  0x009ac410 in __kernel_vsyscall ()
  4 Thread 0xb7536b90 (LWP 16333)  0x009ac410 in __kernel_vsyscall ()
  3 Thread 0xb6b35b90 (LWP 16334)  0x009ac410 in __kernel_vsyscall ()
  2 Thread 0xb603ab90 (LWP 16335)  0x009ac410 in __kernel_vsyscall ()
* 1 Thread 0xb7f69720 (LWP 16331)  0x009ac410 in __kernel_vsyscall ()
(gdb) thread apply all bt

Thread 5 (Thread 0xb7f37b90 (LWP 16332)):
#0  0x009ac410 in __kernel_vsyscall ()
#1  0x006828c2 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x005e1b84 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libc.so.6
#3  0x00dd8b1e in qpid::broker::Timer::run () from /usr/lib/libqpidbroker.so.0
#4  0x00251581 in ?? () from /usr/lib/libqpidcommon.so.0
#5  0x0067e49b in start_thread () from /lib/libpthread.so.0
#6  0x005d542e in clone () from /lib/libc.so.6

Thread 4 (Thread 0xb7536b90 (LWP 16333)):
#0  0x009ac410 in __kernel_vsyscall ()
#1  0x006828c2 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x005e1b84 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libc.so.6
#3  0x00dd8b1e in qpid::broker::Timer::run () from /usr/lib/libqpidbroker.so.0
#4  0x00251581 in ?? () from /usr/lib/libqpidcommon.so.0
#5  0x0067e49b in start_thread () from /lib/libpthread.so.0
#6  0x005d542e in clone () from /lib/libc.so.6

Thread 3 (Thread 0xb6b35b90 (LWP 16334)):
#0  0x009ac410 in __kernel_vsyscall ()
#1  0x00682595 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x005e1b3d in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libc.so.6
#3  0x00dd8907 in qpid::broker::Timer::run () from /usr/lib/libqpidbroker.so.0
#4  0x00251581 in ?? () from /usr/lib/libqpidcommon.so.0
#5  0x0067e49b in start_thread () from /lib/libpthread.so.0
#6  0x005d542e in clone () from /lib/libc.so.6

Thread 2 (Thread 0xb603ab90 (LWP 16335)):
#0  0x009ac410 in __kernel_vsyscall ()
#1  0x006828c2 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x005e1b84 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libc.so.6
#3  0x00dd8b1e in qpid::broker::Timer::run () from /usr/lib/libqpidbroker.so.0
#4  0x00251581 in ?? () from /usr/lib/libqpidcommon.so.0
#5  0x0067e49b in start_thread () from /lib/libpthread.so.0
#6  0x005d542e in clone () from /lib/libc.so.6
---Type <return> to continue, or q <return> to quit---

Thread 1 (Thread 0xb7f69720 (LWP 16331)):
#0  0x009ac410 in __kernel_vsyscall ()
#1  0x005cb973 in poll () from /lib/libc.so.6
#2  0x004957e6 in openais_dispatch_recv (ipc_ctx=<value optimized out>, data=Could not find the frame base for "openais_dispatch_recv".
) at util.c:476
#3  0x004968c3 in cpg_dispatch (handle=<value optimized out>, dispatch_types=<value optimized out>) at cpg.c:266
#4  0x00860db3 in qpid::cluster::Cpg::dispatchOne () from /usr/lib/qpid/daemon/cluster.so
#5  0x00834b4f in qpid::cluster::Cluster::Cluster () from /usr/lib/qpid/daemon/cluster.so
#6  0x008521cc in qpid::cluster::ClusterPlugin::earlyInitialize () from /usr/lib/qpid/daemon/cluster.so
#7  0x00d01684 in qpid::broker::Broker::Broker () from /usr/lib/libqpidbroker.so.0
#8  0x0804dcc0 in ?? ()
#9  0x0804c6c7 in __cxa_pure_virtual ()
#10 0x00519e8c in __libc_start_main () from /lib/libc.so.6
#11 0x0804c051 in __cxa_pure_virtual ()
(gdb)
(gdb) quit
The program is running.  Quit anyway (and detach it)? (y or n) y
Detaching from program: /usr/sbin/qpidd, process 16331

[root@mrg-qe-01 ~]# cat /root/qpid_ptest_cluster_failover_soak/openais.log
Jun 23 13:10:00.691017 [MAIN ] AIS Executive Service RELEASE 'subrev 1358 version 0.80.3'
Jun 23 13:10:00.691355 [MAIN ] Copyright (C) 2002-2006 MontaVista Software, Inc and contributors.
Jun 23 13:10:00.691391 [MAIN ] Copyright (C) 2006 Red Hat, Inc.
Jun 23 13:10:00.691422 [MAIN ] AIS Executive Service: started and ready to provide service.
Jun 23 13:10:00.691452 [MAIN ] openais component openais_cpg loaded.
Jun 23 13:10:00.691481 [MAIN ] Registering service handler 'openais cluster closed process group service v1.01'
Jun 23 13:10:00.691510 [MAIN ] openais component openais_cfg loaded.
Jun 23 13:10:00.691539 [MAIN ] Registering service handler 'openais configuration service'
Jun 23 13:10:00.691568 [MAIN ] openais component openais_msg loaded.
Jun 23 13:10:00.691596 [MAIN ] Registering service handler 'openais message service B.01.01'
Jun 23 13:10:00.691625 [MAIN ] openais component openais_lck loaded.
Jun 23 13:10:00.691652 [MAIN ] Registering service handler 'openais distributed locking service B.01.01'
Jun 23 13:10:00.691681 [MAIN ] openais component openais_evt loaded.
Jun 23 13:10:00.691709 [MAIN ] Registering service handler 'openais event service B.01.01'
Jun 23 13:10:00.691738 [MAIN ] openais component openais_ckpt loaded.
Jun 23 13:10:00.691768 [MAIN ] Registering service handler 'openais checkpoint service B.01.01'
Jun 23 13:10:00.691797 [MAIN ] openais component openais_amf loaded.
Jun 23 13:10:00.691825 [MAIN ] Registering service handler 'openais availability management framework B.01.01'
Jun 23 13:10:00.691853 [MAIN ] openais component openais_clm loaded.
Jun 23 13:10:00.691881 [MAIN ] Registering service handler 'openais cluster membership service B.01.01'
Jun 23 13:10:00.691909 [MAIN ] openais component openais_evs loaded.
Jun 23 13:10:00.691936 [MAIN ] Registering service handler 'openais extended virtual synchrony service'
Jun 23 13:10:00.691965 [print.c:0344] log setup
Jun 23 13:10:00.730788 [TOTEM] Token Timeout (1000 ms) retransmit timeout (238 ms)
Jun 23 13:10:00.730844 [TOTEM] token hold (180 ms) retransmits before loss (4 retrans)
Jun 23 13:10:00.730863 [TOTEM] join (50 ms) send_join (0 ms) consensus (800 ms) merge (200 ms)
Jun 23 13:10:00.730880 [TOTEM] downcheck (1000 ms) fail to recv const (50 msgs)
Jun 23 13:10:00.730894 [TOTEM] seqno unchanged const (30 rotations) Maximum network MTU 1500
Jun 23 13:10:00.730909 [TOTEM] window size per rotation (50 messages) maximum messages per rotation (17 messages)
Jun 23 13:10:00.730924 [TOTEM] send threads (0 threads)
Jun 23 13:10:00.730939 [TOTEM] RRP token expired timeout (238 ms)
Jun 23 13:10:00.730954 [TOTEM] RRP token problem counter (2000 ms)
Jun 23 13:10:00.730968 [TOTEM] RRP threshold (10 problem count)
Jun 23 13:10:00.730983 [TOTEM] RRP mode set to none.
Jun 23 13:10:00.731023 [TOTEM] heartbeat_failures_allowed (0)
Jun 23 13:10:00.731038 [TOTEM] max_network_delay (50 ms)
Jun 23 13:10:00.731081 [TOTEM] HeartBeat is Disabled. To enable set heartbeat_failures_allowed > 0
Jun 23 13:10:00.731583 [TOTEM] Receive multicast socket recv buffer size (262142 bytes).
Jun 23 13:10:00.731611 [TOTEM] Transmit multicast socket send buffer size (262142 bytes).
Jun 23 13:10:00.734500 [TOTEM] The network interface [10.34.33.54] is now up.
Jun 23 13:10:00.734597 [TOTEM] Created or loaded sequence id 0.10.34.33.54 for this ring.
Jun 23 13:10:00.734690 [TOTEM] entering GATHER state from 15.
Jun 23 13:10:00.735182 [SERV ] Initialising service handler 'openais extended virtual synchrony service'
Jun 23 13:10:00.735219 [SERV ] Initialising service handler 'openais cluster membership service B.01.01'
Jun 23 13:10:00.735336 [SERV ] Initialising service handler 'openais availability management framework B.01.01'
Jun 23 13:10:00.735371 [SERV ] Initialising service handler 'openais checkpoint service B.01.01'
Jun 23 13:10:00.735396 [SERV ] Initialising service handler 'openais event service B.01.01'
Jun 23 13:10:00.735432 [SERV ] Initialising service handler 'openais distributed locking service B.01.01'
Jun 23 13:10:00.735456 [SERV ] Initialising service handler 'openais message service B.01.01'
Jun 23 13:10:00.735485 [SERV ] Initialising service handler 'openais configuration service'
Jun 23 13:10:00.735505 [SERV ] Initialising service handler 'openais cluster closed process group service v1.01'
Jun 23 13:10:00.735529 [SYNC ] Not using a virtual synchrony filter.
Jun 23 13:10:02.553022 [TOTEM] The consensus timeout expired.
Jun 23 13:10:02.553073 [TOTEM] entering GATHER state from 3.
Jun 23 13:10:04.371050 [TOTEM] The consensus timeout expired.
Jun 23 13:10:04.371149 [TOTEM] entering GATHER state from 3.
Jun 23 13:10:06.190045 [TOTEM] The consensus timeout expired.
Jun 23 13:10:06.190200 [TOTEM] entering GATHER state from 3.
Jun 23 13:10:08.009046 [TOTEM] The consensus timeout expired.
...
Jun 23 13:12:53.531201 [TOTEM] entering GATHER state from 3.
Jun 23 13:12:55.350109 [TOTEM] The consensus timeout expired.
Jun 23 13:12:55.350202 [TOTEM] entering GATHER state from 3.
Jun 23 13:12:57.169110 [TOTEM] The consensus timeout expired.
Jun 23 13:12:57.169200 [TOTEM] entering GATHER state from 3.
Jun 23 13:12:58.989110 [TOTEM] The consensus timeout expired.
Jun 23 13:12:58.989206 [TOTEM] entering GATHER state from 3.
Jun 23 13:13:00.810111 [TOTEM] The consensus timeout expired.
Jun 23 13:13:00.810204 [TOTEM] entering GATHER state from 3.
Jun 23 13:13:02.631112 [TOTEM] The consensus timeout expired.
Jun 23 13:13:02.631203 [TOTEM] entering GATHER state from 3.
Jun 23 13:13:04.451116 [TOTEM] The consensus timeout expired.
Jun 23 13:13:04.451207 [TOTEM] entering GATHER state from 3.
Jun 23 13:13:06.271108 [TOTEM] The consensus timeout expired.
Jun 23 13:13:06.271200 [TOTEM] entering GATHER state from 3.
Jun 23 13:13:08.015980 [ipc.c:0731] connection received from libais client 8.
Jun 23 13:13:08.090115 [TOTEM] The consensus timeout expired.
Jun 23 13:13:08.090218 [TOTEM] entering GATHER state from 3.
Jun 23 13:13:09.909115 [TOTEM] The consensus timeout expired.
...
Jun 23 13:19:08.769252 [TOTEM] The consensus timeout expired.
Jun 23 13:19:08.769344 [TOTEM] entering GATHER state from 3.

Looks to me like iptable is blocking networking.

I'm sorry and you're indeed right it is iptables issue, not the openais.

-> CLOSED (NOTABUG)

Created attachment 375793 [details]
the bug logs and daemon configurations

I experience the issue again on machines penguin-a1300-01.rhts.bos.redhat.com and ibm-defiant.rhts.eng.bos.redhat.com on latest MRG 1.2 packages:
[root@ibm-defiant ~]# rpm -qa | grep -E '(qpid|openais)'
qpidc-0.5.752581-34.el5
qpid-dotnet-0.4.738274-2.el5
qpidc-rdma-0.5.752581-34.el5
qpidd-rdma-0.5.752581-34.el5
qpidd-acl-0.5.752581-34.el5
qpidc-debuginfo-0.5.752581-34.el5
qpidd-0.5.752581-34.el5
qpidc-devel-0.5.752581-34.el5
python-qpid-0.5.752581-4.el5
qpidd-ssl-0.5.752581-34.el5
qpid-java-client-0.5.751061-9.el5
qpidc-perftest-0.5.752581-34.el5
openais-0.80.6-8.el5_4.1
qpidc-ssl-0.5.752581-34.el5
qpidd-devel-0.5.752581-34.el5
qpidd-xml-0.5.752581-34.el5
qpidd-cluster-0.5.752581-34.el5
qpid-java-common-0.5.751061-9.el5
openais-debuginfo-0.80.6-8.el5_4.1

I'm now pretty sure both machines have SELinux and iptables off as can be seen below...

The openais node shows messages:
Dec  3  8:59:13.681209 [TOTEM] entering GATHER state from 3.
Dec  3  8:59:15.500669 [TOTEM] The consensus timeout expired.
Dec  3  8:59:15.500741 [TOTEM] entering GATHER state from 3.
Dec  3  8:59:17.320273 [TOTEM] The consensus timeout expired.
Dec  3  8:59:17.320324 [TOTEM] entering GATHER state from 3.
Dec  3  8:59:19.139860 [TOTEM] The consensus timeout expired.
...
as shown above, the detailed configs and logs are attached


-> ASSIGNED (target MRG1.3)




Detailed transcripts:

The first machine's daemons started up fine:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Linux penguin-a1300-01.rhts.bos.redhat.com 2.6.18-164.el5 #1 SMP Tue Aug 18 15:51:54 EDT 2009 i686 athlon i386 GNU/Linux
[root@penguin-a1300-01 ~]# rpm -qa | grep -E '(qpid|openais)'
qpidd-0.5.752581-34.el5
qpidc-debuginfo-0.5.752581-34.el5
rh-tests-distribution-MRG-Messaging-qpid_common-1.5-16
qpidc-0.5.752581-34.el5
qpidc-perftest-0.5.752581-34.el5
python-qpid-0.5.752581-4.el5
openais-0.80.6-8.el5_4.1
[root@penguin-a1300-01 ~]# ps auxw | grep -E '(ais|qpid)' | grep -v grep; netstat -nlp | grep -E '(ais|qpid)'|grep -v grep
[root@penguin-a1300-01 ~]# service openais start
Starting OpenAIS daemon (aisexec): [  OK  ]
[root@penguin-a1300-01 ~]# service qpidd start
Starting Qpid AMQP daemon: 2009-dec-03 09:20:00 info Loaded Module: /usr/lib/qpid/daemon/replicating_listener.so
2009-dec-03 09:20:00 info Loaded Module: /usr/lib/qpid/daemon/msgstore.so
2009-dec-03 09:20:00 info Loaded Module: /usr/lib/qpid/daemon/replication_exchange.so
[  OK  ]
2009-dec-03 09:20:01 info Loaded Module: /usr/lib/qpid/daemon/replicating_listener.so
2009-dec-03 09:20:01 info Loaded Module: /usr/lib/qpid/daemon/msgstore.so
2009-dec-03 09:20:01 info Loaded Module: /usr/lib/qpid/daemon/replication_exchange.so
[root@penguin-a1300-01 ~]# !ps
ps auxw | grep -E '(ais|qpid)' | grep -v grep; netstat -nlp | grep -E '(ais|qpid)'|grep -v grep
root     27745  0.2  0.6  14384 14372 pts/2    SLl  09:19   0:00 /usr/sbin/aisexec
qpidd    27783  0.1  0.1  73984  3672 ?        Ssl  09:20   0:00 /usr/sbin/qpidd --daemon --pid-dir /var/run/qpidd --data-dir /var/lib/qpidd
tcp        0      0 0.0.0.0:5672                0.0.0.0:*                   LISTEN      27783/qpidd
udp        0      0 10.16.66.121:54051          0.0.0.0:*                               27745/aisexec
udp        0      0 10.16.66.121:53795          0.0.0.0:*                               27745/aisexec
udp        0      0 255.0.0.12:54051            0.0.0.0:*                               27745/aisexec
unix  2      [ ACC ]     STREAM     LISTENING     88789  27745/aisexec       @libais.socket
[root@penguin-a1300-01 ~]# getenforce
Permissive
[root@penguin-a1300-01 ~]# service iptables status
Firewall is stopped.
[root@penguin-a1300-01 ~]# qpid-config queues
Queue Name                                          Attributes
===========================================================================
reply-penguin-a1300-01.rhts.bos.redhat.com.27818.1  auto-del excl
topic-penguin-a1300-01.rhts.bos.redhat.com.27818.1  auto-del excl





But the second one had problems: (qpidd daemon timeouted, hang in openais_dispatch_recv())
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
[root@ibm-defiant ~]# uname -a
Linux ibm-defiant.rhts.eng.bos.redhat.com 2.6.18-164.el5 #1 SMP Tue Aug 18 15:51:54 EDT 2009 i686 i686 i386 GNU/Linux
[root@ibm-defiant ~]# rpm -qa | grep -E '(qpid|openais)'
qpidc-0.5.752581-34.el5
qpid-dotnet-0.4.738274-2.el5
qpidc-rdma-0.5.752581-34.el5
qpidd-rdma-0.5.752581-34.el5
qpidd-acl-0.5.752581-34.el5
qpidc-debuginfo-0.5.752581-34.el5
qpidd-0.5.752581-34.el5
qpidc-devel-0.5.752581-34.el5
python-qpid-0.5.752581-4.el5
qpidd-ssl-0.5.752581-34.el5
qpid-java-client-0.5.751061-9.el5
qpidc-perftest-0.5.752581-34.el5
rh-tests-distribution-MRG-Messaging-qpid_common-1.5-16
openais-0.80.6-8.el5_4.1
qpidc-ssl-0.5.752581-34.el5
qpidd-devel-0.5.752581-34.el5
qpidd-xml-0.5.752581-34.el5
qpidd-cluster-0.5.752581-34.el5
qpid-java-common-0.5.751061-9.el5
openais-debuginfo-0.80.6-8.el5_4.1
ps auxw | grep -E '(ais|qpid)' | grep -v grep; netstat -nlp | grep -E '(ais|qpid)'|grep -v grep
[root@ibm-defiant ~]# service openais start
Starting OpenAIS daemon (aisexec): [  OK  ]
[root@ibm-defiant ~]# service qpidd start
Starting Qpid AMQP daemon: 2009-dec-03 09:20:03 info Loaded Module: /usr/lib/qpid/daemon/rdma.so
2009-dec-03 09:20:03 info Loaded Module: /usr/lib/qpid/client/rdmaconnector.so
2009-dec-03 09:20:03 info SSL connector not enabled, you must set QPID_SSL_CERT_DB to enable it.
2009-dec-03 09:20:03 info Loaded Module: /usr/lib/qpid/client/sslconnector.so
2009-dec-03 09:20:03 info Loaded Module: /usr/lib/qpid/daemon/cluster.so
2009-dec-03 09:20:03 info Loaded Module: /usr/lib/qpid/daemon/acl.so
2009-dec-03 09:20:03 info Loaded Module: /usr/lib/qpid/daemon/replication_exchange.so
2009-dec-03 09:20:03 info Loaded Module: /usr/lib/qpid/daemon/ssl.so
2009-dec-03 09:20:03 info Loaded Module: /usr/lib/qpid/daemon/msgstore.so
2009-dec-03 09:20:03 info Loaded Module: /usr/lib/qpid/daemon/replicating_listener.so
2009-dec-03 09:20:03 info Loaded Module: /usr/lib/qpid/daemon/xml.so
Timed out waiting for daemon
[FAILED]
[root@ibm-defiant ~]# !ps
ps auxw | grep -E '(ais|qpid)' | grep -v grep; netstat -nlp | grep -E '(ais|qpid)'|grep -v grep
root     12688  0.0  1.6  17512 17500 pts/2    SLl  09:19   0:00 /usr/sbin/aisexec
qpidd    12834  0.0  0.2  57048  2900 ?        Ssl  09:20   0:00 /usr/sbin/qpidd --daemon --pid-dir /var/run/qpidd --data-dir /var/lib/qpidd
udp        0      0 10.16.64.48:54051           0.0.0.0:*                               12688/aisexec
udp        0      0 10.16.64.48:53795           0.0.0.0:*                               12688/aisexec
udp        0      0 255.0.0.12:54051            0.0.0.0:*                               12688/aisexec
unix  2      [ ACC ]     STREAM     LISTENING     219668 12688/aisexec       @libais.socket
[root@ibm-defiant ~]# getenforce
Permissive
[root@ibm-defiant ~]# service iptables status
Firewall is stopped.
[root@ibm-defiant ~]# qpid-config queues
Failed: error - (111, 'Connection refused')
[root@ibm-defiant ~]# pstack 12834
Thread 4 (Thread 0xb7ed9b90 (LWP 12835)):
#0  0x00810402 in __kernel_vsyscall ()
#1  0x008b4b82 in pthread_cond_timedwait@@GLIBC_2.3.2 ()
#2  0x00628414 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libc.so.6
#3  0x004c93be in qpid::broker::Timer::run () from /usr/lib/libqpidbroker.so.0
#4  0x00254871 in ?? () from /usr/lib/libqpidcommon.so.0
#5  0x008b05ab in start_thread () from /lib/libpthread.so.0
#6  0x0061bcfe in clone () from /lib/libc.so.6
Thread 3 (Thread 0xb74d8b90 (LWP 12836)):
#0  0x00810402 in __kernel_vsyscall ()
#1  0x008b4b82 in pthread_cond_timedwait@@GLIBC_2.3.2 ()
#2  0x00628414 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libc.so.6
#3  0x004c93be in qpid::broker::Timer::run () from /usr/lib/libqpidbroker.so.0
#4  0x00254871 in ?? () from /usr/lib/libqpidcommon.so.0
#5  0x008b05ab in start_thread () from /lib/libpthread.so.0
#6  0x0061bcfe in clone () from /lib/libc.so.6
Thread 2 (Thread 0xb6ad7b90 (LWP 12837)):
#0  0x00810402 in __kernel_vsyscall ()
#1  0x008b4855 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x006283cd in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libc.so.6
#3  0x004c91a7 in qpid::broker::Timer::run () from /usr/lib/libqpidbroker.so.0
#4  0x00254871 in ?? () from /usr/lib/libqpidcommon.so.0
#5  0x008b05ab in start_thread () from /lib/libpthread.so.0
#6  0x0061bcfe in clone () from /lib/libc.so.6
Thread 1 (Thread 0xb7f0b720 (LWP 12834)):
#0  0x00810402 in __kernel_vsyscall ()
#1  0x00612023 in poll () from /lib/libc.so.6
#2  0x006c37e6 in openais_dispatch_recv () from /usr/lib/openais/libcpg.so.2
#3  0x006c48c3 in cpg_dispatch () from /usr/lib/openais/libcpg.so.2
#4  0x00a31413 in qpid::cluster::Cpg::dispatchOne ()
#5  0x00a0440e in qpid::cluster::Cluster::Cluster ()
#6  0x00a22e5c in qpid::cluster::ClusterPlugin::earlyInitialize ()
#7  0x003eeb6a in qpid::broker::Broker::Broker ()
#8  0x08050661 in ?? ()
#9  0x0042d640 in qpid::broker::Daemon::fork ()
#10 0x0804de11 in ?? ()
#11 0x0804c6c7 in __cxa_pure_virtual ()
#12 0x0055fe9c in __libc_start_main () from /lib/libc.so.6
#13 0x0804c051 in __cxa_pure_virtual ()
[root@ibm-defiant ~]# gdb
GNU gdb Fedora (6.8-37.el5)
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "i386-redhat-linux-gnu".
(gdb) attach 12834
Attaching to process 12834
Reading symbols from /usr/sbin/qpidd...Reading symbols from /usr/lib/debug/usr/sbin/qpidd.debug...done.
done.
warning: .dynamic section for "/lib/libc.so.6" is not at the expected address
warning: difference appears to be caused by prelink, adjusting expectations
warning: .dynamic section for "/usr/lib/openais/libcpg.so.2" is not at the expected address
warning: difference appears to be caused by prelink, adjusting expectations
warning: .dynamic section for "/usr/lib/libssl3.so" is not at the expected address
warning: difference appears to be caused by prelink, adjusting expectations
warning: .dynamic section for "/usr/lib/libnspr4.so" is not at the expected address
warning: difference appears to be caused by prelink, adjusting expectations
warning: .dynamic section for "/usr/lib/libnssutil3.so" is not at the expected address
warning: difference appears to be caused by prelink, adjusting expectations
warning: .dynamic section for "/usr/lib/libplc4.so" is not at the expected address
warning: difference appears to be caused by prelink, adjusting expectations
warning: .dynamic section for "/usr/lib/libplds4.so" is not at the expected address
warning: difference appears to be caused by prelink, adjusting expectations
Reading symbols from /usr/lib/libqpidbroker.so.0...Reading symbols from /usr/lib/debug/usr/lib/libqpidbroker.so.0.1.0.debug...done.
done.
Loaded symbols for /usr/lib/libqpidbroker.so.0
...
Reading symbols from /usr/lib/libxqilla.so.3...done.
Loaded symbols for /usr/lib/libxqilla.so.3
0x00810402 in __kernel_vsyscall ()
(gdb) info threads
  4 Thread 0xb7ed9b90 (LWP 12835)  0x00810402 in __kernel_vsyscall ()
  3 Thread 0xb74d8b90 (LWP 12836)  0x00810402 in __kernel_vsyscall ()
  2 Thread 0xb6ad7b90 (LWP 12837)  0x00810402 in __kernel_vsyscall ()
* 1 Thread 0xb7f0b720 (LWP 12834)  0x00810402 in __kernel_vsyscall ()
(gdb) thread apply all bt

Thread 4 (Thread 0xb7ed9b90 (LWP 12835)):
#0  0x00810402 in __kernel_vsyscall ()
#1  0x008b4b82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x00628414 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libc.so.6
#3  0x004c93be in qpid::broker::Timer::run (this=<value optimized out>) at qpid/sys/posix/Condition.h:69
#4  0x00254871 in runRunnable (p=Could not find the frame base for "runRunnable".
) at qpid/sys/posix/Thread.cpp:35
#5  0x008b05ab in start_thread () from /lib/libpthread.so.0
#6  0x0061bcfe in clone () from /lib/libc.so.6

Thread 3 (Thread 0xb74d8b90 (LWP 12836)):
#0  0x00810402 in __kernel_vsyscall ()
#1  0x008b4b82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x00628414 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libc.so.6
#3  0x004c93be in qpid::broker::Timer::run (this=<value optimized out>) at qpid/sys/posix/Condition.h:69
#4  0x00254871 in runRunnable (p=Could not find the frame base for "runRunnable".
) at qpid/sys/posix/Thread.cpp:35
#5  0x008b05ab in start_thread () from /lib/libpthread.so.0
#6  0x0061bcfe in clone () from /lib/libc.so.6

Thread 2 (Thread 0xb6ad7b90 (LWP 12837)):
#0  0x00810402 in __kernel_vsyscall ()
#1  0x008b4855 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x006283cd in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libc.so.6
#3  0x004c91a7 in qpid::broker::Timer::run (this=<value optimized out>) at qpid/sys/posix/Condition.h:63
#4  0x00254871 in runRunnable (p=Could not find the frame base for "runRunnable".
) at qpid/sys/posix/Thread.cpp:35
#5  0x008b05ab in start_thread () from /lib/libpthread.so.0
#6  0x0061bcfe in clone () from /lib/libc.so.6

Thread 1 (Thread 0xb7f0b720 (LWP 12834)):
#0  0x00810402 in __kernel_vsyscall ()
#1  0x00612023 in poll () from /lib/libc.so.6
#2  0x006c37e6 in openais_dispatch_recv (ipc_ctx=<value optimized out>, data=Could not find the frame base for "openais_dispatch_recv".
) at util.c:476
#3  0x006c48c3 in cpg_dispatch (handle=<value optimized out>, dispatch_types=<value optimized out>)
    at cpg.c:266
#4  0x00a31413 in qpid::cluster::Cpg::dispatchOne (this=0x8d4b090) at qpid/cluster/Cpg.cpp:139
#5  0x00a0440e in Cluster (this=0x8d4b058, set=@0xa75f24, b=@0x8d49a68) at qpid/cluster/Cluster.cpp:221
---Type <return> to continue, or q <return> to quit---
#6  0x00a22e5c in qpid::cluster::ClusterPlugin::earlyInitialize (this=0xa75f20, target=@0x8d49a6c)
    at qpid/cluster/ClusterPlugin.cpp:137
#7  0x003eeb6a in Broker (this=<value optimized out>, conf=<value optimized out>)
    at qpid/broker/Broker.cpp:211
#8  0x08050661 in QpiddDaemon::child (this=0xbfe18abc) at posix/QpiddBroker.cpp:124
#9  0x0042d640 in qpid::broker::Daemon::fork (this=<value optimized out>) at qpid/broker/Daemon.cpp:85
#10 0x0804de11 in QpiddBroker::execute (this=0xbfe18d45, options=0x8d55c58) at posix/QpiddBroker.cpp:159
#11 0x0804c6c7 in main (argc=6, argv=0xbfe18df4) at qpidd.cpp:77
(gdb)
(gdb) quit
The program is running.  Quit anyway (and detach it)? (y or n) y
Detaching from program: /usr/sbin/qpidd, process 12834

Gordon,

It was closed as not a bug because it was found to be an iptables issue.

OpenAIS will behave poorly with iptables enabled.

Regards
-steve

Any word if this is only an issue in the rhts environment, or happens in all 5.4 setups?

Regards
-steve

Test indication:
Test is currently running, few thousands of cluster restarts performed w/o an issue. Test end is scheduled until Friday March 12, final statement on Friday.

The long term test proved that there is no issue on MRG 1.2 packages and rhel 5.4 latest openais. I'm about to believe that the issue was caused by improper network function or fixed as side-effect of qpid/openais patches.

Tested on 2/4 machine loopping cluster restart for about the week on RHEL 5.4 i386 / x86_64 on packages:
root@mrg-qe-12:~# rpm -qa | grep -E '(qpid|openais)' | sort
openais-0.80.6-8.el5_4.3
openais-debuginfo-0.80.6-8.el5_4.3
openais-devel-0.80.6-8.el5_4.3
python-qpid-0.5.752581-4.el5
qpidc-0.5.752581-34.el5
qpidc-debuginfo-0.5.752581-34.el5
qpidc-devel-0.5.752581-34.el5
qpidc-perftest-0.5.752581-34.el5
qpidc-rdma-0.5.752581-34.el5
qpidc-ssl-0.5.752581-34.el5
qpidd-0.5.752581-34.el5
qpidd-acl-0.5.752581-34.el5
qpidd-cluster-0.5.752581-34.el5
qpidd-devel-0.5.752581-34.el5
qpid-dotnet-0.4.738274-2.el5
qpidd-rdma-0.5.752581-34.el5
qpidd-ssl-0.5.752581-34.el5
qpidd-xml-0.5.752581-34.el5
qpid-java-client-0.5.751061-9.el5
qpid-java-common-0.5.751061-9.el5


-> VERIFIED

    Technical note added. If any revisions are required, please edit the "Technical Notes" field
    accordingly. All revisions will be proofread by the Engineering Content Services team.
    
    New Contents:
A clustered qpidd occasionally hanged in the 'openais_dispatch_recv()' function. This caused the qpidd to not start up. With this update, this behavior no longer occurs and qpidd proceeds to start up as is expected.

An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on therefore solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHSA-2010-0773.html