Mailing List Archive

possible deadlock in lrmd?
Hi,

Senko Rasic proposed a patch for the client unregister which
would prevent a double unref of glib sources (IPC channel).
However, I cannot recall any deadlocks in lrmd.

See http://www.init.hr/dev/cluster/patches/2444.diff

Senko, is this something you observed or you just thought it
might occur?

BTW, this same or very similar procedure is used by all programs
including pacemaker.

Thanks,

Dejan

P.S. Senko, if you want to post to this mailing list, you'll have
to subscribe first.
_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
On Thu, Oct 21, 2010 at 11:57:56AM +0200, Senko Rasic wrote:
> Hi,
>
> I'm replying directly to you with this, feel free to forward to the
> list. For further discussions I could also join the list.

Yes, it would be good.

> On 10/21/2010 11:34 AM, Dejan Muhamedagic wrote:
> >Senko Rasic proposed a patch for the client unregister which
> >would prevent a double unref of glib sources (IPC channel).
> >However, I cannot recall any deadlocks in lrmd.
> >
> >See http://www.init.hr/dev/cluster/patches/2444.diff
> >
> >Senko, is this something you observed or you just thought it
> >might occur?
>
> This is what I've observed happening whenever I had g_type_init()
> invoked either in the lrmd itself, or in the plugin. g_type_init()
> initialises the glib type system, which is needed for the dbus glib
> proxies to work.
>
> So, when g_type_init() was called earlier, the deadlock would
> eventually happen in the part of the code I patched.
>
> It should be very easy to test; just try using lrmd with
> g_type_init() and without, and it shoudl be apparent it gets blocked
> after the first request, no matter which plugin serves the req.

Perhaps it would help to do g_type_init() on lrmd startup before
doing any glib2 related stuff (in particular the IPC). Not sure,
but it could be a problem with locking, i.e. that the deadlock
you saw was actually lrmd waiting on some mutex. lrmd is not a
threaded application and therefore has no g_thread_init().
Apparently, g_thread_init() is needed (or recommended) before
g_type_init().

There's also a recent patch which enables threading within
g_type_init():

http://osdir.com/ml/svn-commits-list/2010-01/msg03809.html

Could you give it a try and move g_type_init() to init_start()
before any other glib calls. Perhaps with g_thread_init() too.

Though I'm not sure if this is going to work at all.

Cheers,

Dejan

> >BTW, this same or very similar procedure is used by all programs
> >including pacemaker.
>
> Right, the code I commented out didn't look obviusly wrong to me (so
> I added a comment about the potential ref leak). Unfortunately I
> don't know much about lrmd internals and haven't been able to reason
> out why this would be happening.
>
> BR,
> Senko
>
> --
> Senko Rasic, DobarKod d.o.o. <senko.rasic@dobarkod.hr>
> http://dobarkod.hr/
_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
Hi,

On Thu, Oct 21, 2010 at 01:20:29PM +0200, Dejan Muhamedagic wrote:
> On Thu, Oct 21, 2010 at 11:57:56AM +0200, Senko Rasic wrote:
> > Hi,
> >
> > I'm replying directly to you with this, feel free to forward to the
> > list. For further discussions I could also join the list.
>
> Yes, it would be good.
>
> > On 10/21/2010 11:34 AM, Dejan Muhamedagic wrote:
> > >Senko Rasic proposed a patch for the client unregister which
> > >would prevent a double unref of glib sources (IPC channel).
> > >However, I cannot recall any deadlocks in lrmd.
> > >
> > >See http://www.init.hr/dev/cluster/patches/2444.diff
> > >
> > >Senko, is this something you observed or you just thought it
> > >might occur?
> >
> > This is what I've observed happening whenever I had g_type_init()
> > invoked either in the lrmd itself, or in the plugin. g_type_init()
> > initialises the glib type system, which is needed for the dbus glib
> > proxies to work.
> >
> > So, when g_type_init() was called earlier, the deadlock would
> > eventually happen in the part of the code I patched.
> >
> > It should be very easy to test; just try using lrmd with
> > g_type_init() and without, and it shoudl be apparent it gets blocked
> > after the first request, no matter which plugin serves the req.
>
> Perhaps it would help to do g_type_init() on lrmd startup before
> doing any glib2 related stuff (in particular the IPC). Not sure,
> but it could be a problem with locking, i.e. that the deadlock
> you saw was actually lrmd waiting on some mutex. lrmd is not a
> threaded application and therefore has no g_thread_init().
> Apparently, g_thread_init() is needed (or recommended) before
> g_type_init().
>
> There's also a recent patch which enables threading within
> g_type_init():
>
> http://osdir.com/ml/svn-commits-list/2010-01/msg03809.html
>
> Could you give it a try and move g_type_init() to init_start()
> before any other glib calls. Perhaps with g_thread_init() too.

Any news here?

Cheers,

Dejan

> Though I'm not sure if this is going to work at all.
>
> Cheers,
>
> Dejan
>
> > >BTW, this same or very similar procedure is used by all programs
> > >including pacemaker.
> >
> > Right, the code I commented out didn't look obviusly wrong to me (so
> > I added a comment about the potential ref leak). Unfortunately I
> > don't know much about lrmd internals and haven't been able to reason
> > out why this would be happening.
> >
> > BR,
> > Senko
> >
> > --
> > Senko Rasic, DobarKod d.o.o. <senko.rasic@dobarkod.hr>
> > http://dobarkod.hr/
> _______________________________________________________
> Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
> http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
> Home Page: http://linux-ha.org/
_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
Hi,
I have a problem that looks similar to that reported "possible deadlock
in lrmd" on 21st Oct

When running lradmin -C to list classes the first time it comes back
immediately with the expected list e.g.

root@node1:/home# lrmadmin -C
There are 5 RA classes supported:
lsb
ocf
stonith
upstart
heartbeat

All subsequent attempts lrmadmin hangs and never comes back (you have to kill
with crtl-C). This is repeatable on all the machines I have tried it on.
reboot appears to be the only cure as corosync stop baulks on
Waiting for corosync services to unload:.........

The environment is compiled from source (as per
http://www.clusterlabs.org/wiki/Install#From_Source) on a clean maverick server (both 32 and 64 bit)

Versions are
Cluster-Resource-Agents-051972b5cfd
Pacemaker-1-0-b2e39d318fda
Reusable-Cluster-Components-8658bcdd4511
flatiron - not sure but downloaded Friday 19th


Strace suggests that lrmadmin has stuck on
/var/run.heartbeat/lrm_cmd_sock reporting "resource temporarily
unavailable" but never responds to the outbound message :

17:43:41.328500 connect(3, {sa_family=AF_FILE,
path="/var/run/heartbeat/lrm_cmd_sock"}, 110) = 0
17:43:41.328572 getsockopt(3, SOL_SOCKET, SO_PEERCRED,
"\t\4\0\0\0\0\0\0\0\0\0\0", [12]) = 0
17:43:41.328788 getegid() = 0
17:43:41.328846 getuid() = 0
17:43:41.328970 recvfrom(3, 0x17f1e70, 4048, 64, 0, 0) = -1 EAGAIN
(Resource temporarily unavailable)
17:43:41.329050 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
17:43:41.329154 recvfrom(3, 0x17f1e70, 4048, 64, 0, 0) = -1 EAGAIN
(Resource temporarily unavailable)
17:43:41.329202 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
17:43:41.329263 sendto(3,
"F\0\0\0\315\253\0\0>>>\nlrm_t=reg\nlrm_app=lr"..., 78,
MSG_DONTWAIT|MSG_NOSIGNAL, NULL, 0) = 78
17:43:41.329337 recvfrom(3, 0x17f1e70, 4048, 64, 0, 0) = -1 EAGAIN
(Resource temporarily unavailable)
17:43:41.329380 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
17:43:41.329420 recvfrom(3, 0x17f1e70, 4048, 64, 0, 0) = -1 EAGAIN
(Resource temporarily unavailable)
17:43:41.329458 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
17:43:41.329497 recvfrom(3, 0x17f1e70, 4048, 64, 0, 0) = -1 EAGAIN
(Resource temporarily unavailable)
17:43:41.329535 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
17:43:41.329574 recvfrom(3, 0x17f1e70, 4048, 64, 0, 0) = -1 EAGAIN
(Resource temporarily unavailable)
17:43:41.329613 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
17:43:41.329651 poll([{fd=3, events=POLLIN}], 1, -1 <unfinished ...>


The lrmd process is still alive and there is nothing logged in
/var/log/daemon.log. Its strace implies it never even saw the request on
the socket. The process still has 3 file handles open on it:
root@node1:~# lsof /var/run/heartbeat/lrm_cmd_sock
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
lrmd 1420 root 3u unix 0xffff88001e011040 0t0 8732
/var/run/heartbeat/lrm_cmd_sock
lrmd 1420 root 9u unix 0xffff88001e0b4d00 0t0 8782
/var/run/heartbeat/lrm_cmd_sock
lrmd 1420 root 11u unix 0xffff88001e1a9d40 0t0 10211
/var/run/heartbeat/lrm_cmd_sock



A good strace (ie lradmin -C after a reboot) starts identically to the
strace above but receives a response from lrmd:
...
20:12:48.774239 poll([{fd=3, events=POLLIN}], 1, -1) = 1 ([{fd=3,
revents=POLLIN}])
20:12:48.774603 recvfrom(3, "
\0\0\0\315\253\0\0>>>\nlrm_t=return\nlrm_ret"..., 4048, MSG_DONTWAIT,
NULL, NULL) = 40
20:12:48.774661 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
20:12:48.774709 recvfrom(3, 0x1049e98, 4008, 64, 0, 0) = -1 EAGAIN
(Resource temporarily unavailable)
20:12:48.774756 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
20:12:48.774804 recvfrom(3, 0x1049e98, 4008, 64, 0, 0) = -1 EAGAIN
(Resource temporarily unavailable)
20:12:48.774851 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
20:12:48.774898 recvfrom(3, 0x1049e98, 4008, 64, 0, 0) = -1 EAGAIN
(Resource temporarily unavailable)
20:12:48.774945 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
20:12:48.775161 recvfrom(3, 0x1049e98, 4008, 64, 0, 0) = -1 EAGAIN
(Resource temporarily unavailable)
20:12:48.775210 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
20:12:48.775257 recvfrom(3, 0x1049e98, 4008, 64, 0, 0) = -1 EAGAIN
(Resource temporarily unavailable)
20:12:48.775304 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
20:12:48.775444 socket(PF_FILE, SOCK_STREAM, 0) = 4
20:12:48.775610 fcntl(4, F_GETFL) = 0x2 (flags O_RDWR)
20:12:48.775686 fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK) = 0
20:12:48.775841 connect(4, {sa_family=AF_FILE,
path="/var/run/heartbeat/lrm_callback_sock"}, 110) = 0
20:12:48.775907 getsockopt(4, SOL_SOCKET, SO_PEERCRED,
20:12:48.775907 getsockopt(4, SOL_SOCKET, SO_PEERCRED,
"\214\5\0\0\0\0\0\0\0\0\0\0", [12]) = 0
...


Other commands like "crm configure verify" exhibits the same "hang"
although I have not traced these. I guess they must use lrmd too.
oYou can throw a SIGUSR1 to lrmd to print some debug.
This is the what was shown just after I executed the first
lrmadmin -C
Nov 22 21:12:39 node1 lrmd: [1038]: debug: on_op_done: BEGIN resource dump
Nov 22 21:12:39 node1 lrmd: [1038]: debug: on_op_done: resource vsftpd/vsftpd/upstart/<null>
Nov 22 21:12:39 node1 lrmd: [1038]: debug: on_op_done: rsc->op_list...
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->op_list: lrmd_op: operation monitor[20] on upstart::vsftpd::vsftpd for client 1041, its parameters: CRM_meta_name=[monitor] cr
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->op_list: lrmd_op2: rt_tag: 0, interval: 5000, delay: 0
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->op_list: lrmd_op3: t_recv: 210940ms, t_add: 20ms, t_perform: 20ms, t_done: 0ms, t_rcchange: 210940ms
Nov 22 21:12:39 node1 lrmd: [1038]: debug: on_op_done: rsc->repeat_op_list...
Nov 22 21:12:39 node1 lrmd: [1038]: debug: on_op_done: rsc->last_op_done...
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_done: lrmd_op: operation monitor[20] on upstart::vsftpd::vsftpd for client 1041, its parameters: CRM_meta_name=[monito
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_done: lrmd_op2: rt_tag: 0, interval: 5000, delay: 0
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_done: lrmd_op3: t_recv: 210940ms, t_add: 5040ms, t_perform: 5040ms, t_done: 5020ms, t_rcchange: 210940ms
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op: operation monitor[5] on upstart::vsftpd::vsftpd for client 1041, its parameters: crm_feature_set=[3.0.
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op2: rt_tag: 0, interval: 0, delay: 0
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op3: t_recv: 214510ms, t_add: 214510ms, t_perform: 214510ms, t_done: 214470ms, t_rcchange: 214510ms
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op: operation stop[8] on upstart::vsftpd::vsftpd for client 1041, its parameters: crm_feature_set=[3.0.1]
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op2: rt_tag: 0, interval: 0, delay: 0
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op3: t_recv: 213210ms, t_add: 213210ms, t_perform: 213210ms, t_done: 213180ms, t_rcchange: 213210ms
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op: operation monitor[20] on upstart::vsftpd::vsftpd for client 1041, its parameters: CRM_meta_name=[monit
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op2: rt_tag: 0, interval: 5000, delay: 0
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op3: t_recv: 210940ms, t_add: 5040ms, t_perform: 5040ms, t_done: 5020ms, t_rcchange: 210940ms
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op: operation start[19] on upstart::vsftpd::vsftpd for client 1041, its parameters: crm_feature_set=[3.0.1
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op2: rt_tag: 0, interval: 0, delay: 0
Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op3: t_recv: 210990ms, t_add: 210990ms, t_perform: 210990ms, t_done: 210960ms, t_rcchange: 210990ms
Nov 22 21:12:39 node1 lrmd: [1038]: debug: on_op_done: END resource dump
Nov 22 21:12:39 node1 lrmd: [1038]: debug: on_op_done:operation monitor[20] on upstart::vsftpd::vsftpd for client 1041, its parameters: CRM_meta_name=[monitor] crm_feature_se
Nov 22 21:12:39 node1 lrmd: [1038]: debug: lrmd_op_destroy: free the operation monitor[20] on upstart::vsftpd::vsftpd for client 1041, its parameters: CRM_meta_name=[monitor]
Nov 22 21:12:39 node1 lrmd: [1038]: debug: replace_last_op: replace last op monitor_5000 for client crmd
Nov 22 21:12:39 node1 lrmd: [1038]: debug: lrmd_op_destroy: free the operation monitor[20] on upstart::vsftpd::vsftpd for client 1041, its parameters: CRM_meta_name=[monitor]
Nov 22 21:12:39 node1 lrmd: [1038]: debug: to_repeatlist: repeat operation monitor[20] on upstart::vsftpd::vsftpd for client 1041, its parameters: CRM_meta_name=[monitor] crm
Nov 22 21:12:39 node1 lrmd: [1038]: debug: lrmd_op_destroy: free the operation monitor[20] on upstart::vsftpd::vsftpd for client 1041, its parameters: CRM_meta_name=[monitor]
Nov 22 21:12:39 node1 lrmd: [1038]: debug: perform_op: no op to perform?
Nov 22 21:12:42 node1 lrmd: [1038]: debug: G_main_IPC_Channel_constructor(sock=11,11)
Nov 22 21:12:42 node1 lrmd: [1038]: debug: dumping request: >>>#012lrm_t=reg#012lrm_app=lrmadmin#012lrm_pid=2438#012lrm_gid=0#012lrm_uid=0#012<<<
Nov 22 21:12:42 node1 lrmd: [1038]: debug: on_msg_register:client lrmadmin [2438] registered
Nov 22 21:12:42 node1 lrmd: [1038]: debug: G_main_IPC_Channel_constructor(sock=12,12)
Nov 22 21:12:42 node1 lrmd: [1038]: debug: dumping request: >>>#012lrm_t=rclasses#012<<<
Nov 22 21:12:42 node1 lrmd: [1038]: debug: on_msg_get_rsc_classes:client [2438] wants to get rsc classes
Nov 22 21:12:42 node1 lrmd: [1038]: debug: on_receive_cmd: the IPC to client [pid:2438] disconnected.
Nov 22 21:12:42 node1 lrmd: [1038]: debug: G_CH_destroy_int(chp=0x25e5830, sock=11) {
Nov 22 21:12:42 node1 lrmd: [1038]: debug: G_CH_destroy_int: Calling dnotify(sock=11, arg=0x25ea310) function
Nov 22 21:12:42 node1 lrmd: [1038]: debug: G_main_del_IPC_Channel(sock=11)

lrmd doesnt respond to subsequent signal requests so I cannot get any further debug using this technique.

backtrace from gdb shows lrmd to be in a lock_wait
#0 0x00007f7e5f8ba6b4 in __lll_lock_wait () from /lib/libpthread.so.0
#1 0x00007f7e5f8b5849 in _L_lock_953 () from /lib/libpthread.so.0
#2 0x00007f7e5f8b566b in pthread_mutex_lock () from /lib/libpthread.so.0
#3 0x00007f7e601b0806 in g_main_context_find_source_by_id () from /lib/libglib-2.0.so.0
#4 0x00007f7e601b08fe in g_source_remove () from /lib/libglib-2.0.so.0
#5 0x00007f7e61568ba1 in G_main_del_IPC_Channel (chp=0x11deed0) at GSource.c:495
#6 0x00000000004065a1 in on_remove_client (user_data=0x11df8e0) at lrmd.c:1526
#7 0x00007f7e615694ca in G_CH_destroy_int (source=0x11deed0) at GSource.c:675
#8 0x00007f7e601adc11 in ?? () from /lib/libglib-2.0.so.0
#9 0x00007f7e601ae428 in g_main_context_dispatch () from /lib/libglib-2.0.so.0
#10 0x00007f7e601b22a8 in ?? () from /lib/libglib-2.0.so.0
#11 0x00007f7e601b27b5 in g_main_loop_run () from /lib/libglib-2.0.so.0
#12 0x0000000000405d32 in init_start () at lrmd.c:1267
#13 0x0000000000404f7a in main (argc=1, argv=0x7fff91e24478) at lrmd.c:835


Looking at the source code is that upon lrmadmin client disconnecting from
lrmd's cmd socket (having got what it needs) lrmd is left to tidy up by
deleting the client event source from the GMainContext GLib loop. It is in the
process of calling g_source_remove() which then hangs deep inside GLib on a
mutex lock.

On the surface the overall sequence makes sense but the hang doesnt and
clearly shouldnt happen. I am at a loss as to whether it is a GLib
issues (unlikely I would have thought?) or its an lrmd bug.

IMHO lrmd should NEVER hang!

Thanks
Dave
_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
Hi,

On Tue, Nov 23, 2010 at 11:03:33PM +0000, Dave Williams wrote:
> Hi,
> I have a problem that looks similar to that reported "possible deadlock
> in lrmd" on 21st Oct
>
> When running lradmin -C to list classes the first time it comes back
> immediately with the expected list e.g.
>
> root@node1:/home# lrmadmin -C
> There are 5 RA classes supported:
> lsb
> ocf
> stonith
> upstart
> heartbeat
>
> All subsequent attempts lrmadmin hangs and never comes back (you have to kill
> with crtl-C). This is repeatable on all the machines I have tried it on.

I'm afraid that this was to be expected.

> reboot appears to be the only cure as corosync stop baulks on
> Waiting for corosync services to unload:.........
>
> The environment is compiled from source (as per
> http://www.clusterlabs.org/wiki/Install#From_Source) on a clean maverick server (both 32 and 64 bit)
>
> Versions are
> Cluster-Resource-Agents-051972b5cfd
> Pacemaker-1-0-b2e39d318fda
> Reusable-Cluster-Components-8658bcdd4511
> flatiron - not sure but downloaded Friday 19th
>
>
> Strace suggests that lrmadmin has stuck on
> /var/run.heartbeat/lrm_cmd_sock reporting "resource temporarily
> unavailable" but never responds to the outbound message :
>
> 17:43:41.328500 connect(3, {sa_family=AF_FILE,
> path="/var/run/heartbeat/lrm_cmd_sock"}, 110) = 0
> 17:43:41.328572 getsockopt(3, SOL_SOCKET, SO_PEERCRED,
> "\t\4\0\0\0\0\0\0\0\0\0\0", [12]) = 0
> 17:43:41.328788 getegid() = 0
> 17:43:41.328846 getuid() = 0
> 17:43:41.328970 recvfrom(3, 0x17f1e70, 4048, 64, 0, 0) = -1 EAGAIN
> (Resource temporarily unavailable)
> 17:43:41.329050 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
> 17:43:41.329154 recvfrom(3, 0x17f1e70, 4048, 64, 0, 0) = -1 EAGAIN
> (Resource temporarily unavailable)
> 17:43:41.329202 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
> 17:43:41.329263 sendto(3,
> "F\0\0\0\315\253\0\0>>>\nlrm_t=reg\nlrm_app=lr"..., 78,
> MSG_DONTWAIT|MSG_NOSIGNAL, NULL, 0) = 78
> 17:43:41.329337 recvfrom(3, 0x17f1e70, 4048, 64, 0, 0) = -1 EAGAIN
> (Resource temporarily unavailable)
> 17:43:41.329380 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
> 17:43:41.329420 recvfrom(3, 0x17f1e70, 4048, 64, 0, 0) = -1 EAGAIN
> (Resource temporarily unavailable)
> 17:43:41.329458 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
> 17:43:41.329497 recvfrom(3, 0x17f1e70, 4048, 64, 0, 0) = -1 EAGAIN
> (Resource temporarily unavailable)
> 17:43:41.329535 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
> 17:43:41.329574 recvfrom(3, 0x17f1e70, 4048, 64, 0, 0) = -1 EAGAIN
> (Resource temporarily unavailable)
> 17:43:41.329613 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
> 17:43:41.329651 poll([{fd=3, events=POLLIN}], 1, -1 <unfinished ...>
>
>
> The lrmd process is still alive and there is nothing logged in
> /var/log/daemon.log. Its strace implies it never even saw the request on
> the socket. The process still has 3 file handles open on it:
> root@node1:~# lsof /var/run/heartbeat/lrm_cmd_sock
> COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
> lrmd 1420 root 3u unix 0xffff88001e011040 0t0 8732
> /var/run/heartbeat/lrm_cmd_sock
> lrmd 1420 root 9u unix 0xffff88001e0b4d00 0t0 8782
> /var/run/heartbeat/lrm_cmd_sock
> lrmd 1420 root 11u unix 0xffff88001e1a9d40 0t0 10211
> /var/run/heartbeat/lrm_cmd_sock
>
>
>
> A good strace (ie lradmin -C after a reboot) starts identically to the
> strace above but receives a response from lrmd:
> ...
> 20:12:48.774239 poll([{fd=3, events=POLLIN}], 1, -1) = 1 ([{fd=3,
> revents=POLLIN}])
> 20:12:48.774603 recvfrom(3, "
> \0\0\0\315\253\0\0>>>\nlrm_t=return\nlrm_ret"..., 4048, MSG_DONTWAIT,
> NULL, NULL) = 40
> 20:12:48.774661 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
> 20:12:48.774709 recvfrom(3, 0x1049e98, 4008, 64, 0, 0) = -1 EAGAIN
> (Resource temporarily unavailable)
> 20:12:48.774756 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
> 20:12:48.774804 recvfrom(3, 0x1049e98, 4008, 64, 0, 0) = -1 EAGAIN
> (Resource temporarily unavailable)
> 20:12:48.774851 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
> 20:12:48.774898 recvfrom(3, 0x1049e98, 4008, 64, 0, 0) = -1 EAGAIN
> (Resource temporarily unavailable)
> 20:12:48.774945 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
> 20:12:48.775161 recvfrom(3, 0x1049e98, 4008, 64, 0, 0) = -1 EAGAIN
> (Resource temporarily unavailable)
> 20:12:48.775210 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
> 20:12:48.775257 recvfrom(3, 0x1049e98, 4008, 64, 0, 0) = -1 EAGAIN
> (Resource temporarily unavailable)
> 20:12:48.775304 poll([{fd=3, events=0}], 1, 0) = 0 (Timeout)
> 20:12:48.775444 socket(PF_FILE, SOCK_STREAM, 0) = 4
> 20:12:48.775610 fcntl(4, F_GETFL) = 0x2 (flags O_RDWR)
> 20:12:48.775686 fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK) = 0
> 20:12:48.775841 connect(4, {sa_family=AF_FILE,
> path="/var/run/heartbeat/lrm_callback_sock"}, 110) = 0
> 20:12:48.775907 getsockopt(4, SOL_SOCKET, SO_PEERCRED,
> 20:12:48.775907 getsockopt(4, SOL_SOCKET, SO_PEERCRED,
> "\214\5\0\0\0\0\0\0\0\0\0\0", [12]) = 0
> ...
>
>
> Other commands like "crm configure verify" exhibits the same "hang"
> although I have not traced these. I guess they must use lrmd too.
> oYou can throw a SIGUSR1 to lrmd to print some debug.
> This is the what was shown just after I executed the first
> lrmadmin -C
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: on_op_done: BEGIN resource dump
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: on_op_done: resource vsftpd/vsftpd/upstart/<null>
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: on_op_done: rsc->op_list...
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->op_list: lrmd_op: operation monitor[20] on upstart::vsftpd::vsftpd for client 1041, its parameters: CRM_meta_name=[monitor] cr
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->op_list: lrmd_op2: rt_tag: 0, interval: 5000, delay: 0
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->op_list: lrmd_op3: t_recv: 210940ms, t_add: 20ms, t_perform: 20ms, t_done: 0ms, t_rcchange: 210940ms
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: on_op_done: rsc->repeat_op_list...
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: on_op_done: rsc->last_op_done...
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_done: lrmd_op: operation monitor[20] on upstart::vsftpd::vsftpd for client 1041, its parameters: CRM_meta_name=[monito
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_done: lrmd_op2: rt_tag: 0, interval: 5000, delay: 0
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_done: lrmd_op3: t_recv: 210940ms, t_add: 5040ms, t_perform: 5040ms, t_done: 5020ms, t_rcchange: 210940ms
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op: operation monitor[5] on upstart::vsftpd::vsftpd for client 1041, its parameters: crm_feature_set=[3.0.
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op2: rt_tag: 0, interval: 0, delay: 0
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op3: t_recv: 214510ms, t_add: 214510ms, t_perform: 214510ms, t_done: 214470ms, t_rcchange: 214510ms
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op: operation stop[8] on upstart::vsftpd::vsftpd for client 1041, its parameters: crm_feature_set=[3.0.1]
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op2: rt_tag: 0, interval: 0, delay: 0
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op3: t_recv: 213210ms, t_add: 213210ms, t_perform: 213210ms, t_done: 213180ms, t_rcchange: 213210ms
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op: operation monitor[20] on upstart::vsftpd::vsftpd for client 1041, its parameters: CRM_meta_name=[monit
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op2: rt_tag: 0, interval: 5000, delay: 0
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op3: t_recv: 210940ms, t_add: 5040ms, t_perform: 5040ms, t_done: 5020ms, t_rcchange: 210940ms
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op: operation start[19] on upstart::vsftpd::vsftpd for client 1041, its parameters: crm_feature_set=[3.0.1
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op2: rt_tag: 0, interval: 0, delay: 0
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: rsc->last_op_table: lrmd_op3: t_recv: 210990ms, t_add: 210990ms, t_perform: 210990ms, t_done: 210960ms, t_rcchange: 210990ms
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: on_op_done: END resource dump
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: on_op_done:operation monitor[20] on upstart::vsftpd::vsftpd for client 1041, its parameters: CRM_meta_name=[monitor] crm_feature_se
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: lrmd_op_destroy: free the operation monitor[20] on upstart::vsftpd::vsftpd for client 1041, its parameters: CRM_meta_name=[monitor]
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: replace_last_op: replace last op monitor_5000 for client crmd
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: lrmd_op_destroy: free the operation monitor[20] on upstart::vsftpd::vsftpd for client 1041, its parameters: CRM_meta_name=[monitor]
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: to_repeatlist: repeat operation monitor[20] on upstart::vsftpd::vsftpd for client 1041, its parameters: CRM_meta_name=[monitor] crm
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: lrmd_op_destroy: free the operation monitor[20] on upstart::vsftpd::vsftpd for client 1041, its parameters: CRM_meta_name=[monitor]
> Nov 22 21:12:39 node1 lrmd: [1038]: debug: perform_op: no op to perform?
> Nov 22 21:12:42 node1 lrmd: [1038]: debug: G_main_IPC_Channel_constructor(sock=11,11)
> Nov 22 21:12:42 node1 lrmd: [1038]: debug: dumping request: >>>#012lrm_t=reg#012lrm_app=lrmadmin#012lrm_pid=2438#012lrm_gid=0#012lrm_uid=0#012<<<
> Nov 22 21:12:42 node1 lrmd: [1038]: debug: on_msg_register:client lrmadmin [2438] registered
> Nov 22 21:12:42 node1 lrmd: [1038]: debug: G_main_IPC_Channel_constructor(sock=12,12)
> Nov 22 21:12:42 node1 lrmd: [1038]: debug: dumping request: >>>#012lrm_t=rclasses#012<<<
> Nov 22 21:12:42 node1 lrmd: [1038]: debug: on_msg_get_rsc_classes:client [2438] wants to get rsc classes
> Nov 22 21:12:42 node1 lrmd: [1038]: debug: on_receive_cmd: the IPC to client [pid:2438] disconnected.
> Nov 22 21:12:42 node1 lrmd: [1038]: debug: G_CH_destroy_int(chp=0x25e5830, sock=11) {
> Nov 22 21:12:42 node1 lrmd: [1038]: debug: G_CH_destroy_int: Calling dnotify(sock=11, arg=0x25ea310) function
> Nov 22 21:12:42 node1 lrmd: [1038]: debug: G_main_del_IPC_Channel(sock=11)
>
> lrmd doesnt respond to subsequent signal requests so I cannot get any further debug using this technique.
>
> backtrace from gdb shows lrmd to be in a lock_wait
> #0 0x00007f7e5f8ba6b4 in __lll_lock_wait () from /lib/libpthread.so.0
> #1 0x00007f7e5f8b5849 in _L_lock_953 () from /lib/libpthread.so.0
> #2 0x00007f7e5f8b566b in pthread_mutex_lock () from /lib/libpthread.so.0
> #3 0x00007f7e601b0806 in g_main_context_find_source_by_id () from /lib/libglib-2.0.so.0
> #4 0x00007f7e601b08fe in g_source_remove () from /lib/libglib-2.0.so.0
> #5 0x00007f7e61568ba1 in G_main_del_IPC_Channel (chp=0x11deed0) at GSource.c:495
> #6 0x00000000004065a1 in on_remove_client (user_data=0x11df8e0) at lrmd.c:1526
> #7 0x00007f7e615694ca in G_CH_destroy_int (source=0x11deed0) at GSource.c:675
> #8 0x00007f7e601adc11 in ?? () from /lib/libglib-2.0.so.0
> #9 0x00007f7e601ae428 in g_main_context_dispatch () from /lib/libglib-2.0.so.0
> #10 0x00007f7e601b22a8 in ?? () from /lib/libglib-2.0.so.0
> #11 0x00007f7e601b27b5 in g_main_loop_run () from /lib/libglib-2.0.so.0
> #12 0x0000000000405d32 in init_start () at lrmd.c:1267
> #13 0x0000000000404f7a in main (argc=1, argv=0x7fff91e24478) at lrmd.c:835
>
>
> Looking at the source code is that upon lrmadmin client disconnecting from
> lrmd's cmd socket (having got what it needs) lrmd is left to tidy up by
> deleting the client event source from the GMainContext GLib loop. It is in the
> process of calling g_source_remove() which then hangs deep inside GLib on a
> mutex lock.
>
> On the surface the overall sequence makes sense but the hang doesnt and
> clearly shouldnt happen. I am at a loss as to whether it is a GLib
> issues (unlikely I would have thought?) or its an lrmd bug.

It's neither. It's bad usage of glib.

> IMHO lrmd should NEVER hang!

If you don't use upstart, it won't hang.

Thanks,

Dejan

> Thanks
> Dave
> _______________________________________________________
> Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
> http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
> Home Page: http://linux-ha.org/
_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
On 10:35, Wed 24 Nov 10, Dejan Muhamedagic wrote:
> Hi,
>
> On Tue, Nov 23, 2010 at 11:03:33PM +0000, Dave Williams wrote:
> > Hi,
> > I have a problem that looks similar to that reported "possible deadlock
> > in lrmd" on 21st Oct
> >
> > When running lradmin -C to list classes the first time it comes back
> > immediately with the expected list e.g.
> >
> > root@node1:/home# lrmadmin -C
> > There are 5 RA classes supported:
> > lsb
> > ocf
> > stonith
> > upstart
> > heartbeat
> >
> > All subsequent attempts lrmadmin hangs and never comes back (you have to kill
> > with crtl-C). This is repeatable on all the machines I have tried it on.
>
> I'm afraid that this was to be expected.
Hi Dejan - thanks for your reply.

I'm not sure which you imply:
a) Its known to be buggy?
b) Its working as designed?
I presume a).

.....

> > On the surface the overall sequence makes sense but the hang doesnt and
> > clearly shouldnt happen. I am at a loss as to whether it is a GLib
> > issues (unlikely I would have thought?) or its an lrmd bug.
>
> It's neither. It's bad usage of glib.
>
Is there anyone working on resolving this? I'm happy to help but dont
have the time to debug further at present - not being a glib expert.
I have other critical software projects to work on and just need
something that works in this area!

> > IMHO lrmd should NEVER hang!
>
> If you don't use upstart, it won't hang.

Sadly I need upstart. Thats one reason I got into this situation in the
first place!

I currently have a production clustered server down because of this and
the fact that ubuntu (I'm advised) have an inconsistently compiled set
of HA components. Certaintly both lucid and maverick released packages
leave defunct processes lying around and give highly unreliable
operation :-(

Dave
_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
Hi,

On Wed, Nov 24, 2010 at 10:52:23AM +0000, Dave Williams wrote:
> On 10:35, Wed 24 Nov 10, Dejan Muhamedagic wrote:
> > Hi,
> >
> > On Tue, Nov 23, 2010 at 11:03:33PM +0000, Dave Williams wrote:
> > > Hi,
> > > I have a problem that looks similar to that reported "possible deadlock
> > > in lrmd" on 21st Oct
> > >
> > > When running lradmin -C to list classes the first time it comes back
> > > immediately with the expected list e.g.
> > >
> > > root@node1:/home# lrmadmin -C
> > > There are 5 RA classes supported:
> > > lsb
> > > ocf
> > > stonith
> > > upstart
> > > heartbeat
> > >
> > > All subsequent attempts lrmadmin hangs and never comes back (you have to kill
> > > with crtl-C). This is repeatable on all the machines I have tried it on.
> >
> > I'm afraid that this was to be expected.
> Hi Dejan - thanks for your reply.
>
> I'm not sure which you imply:
> a) Its known to be buggy?
> b) Its working as designed?
> I presume a).

It is somewhat technical, but basically it's a).

> .....
>
> > > On the surface the overall sequence makes sense but the hang doesnt and
> > > clearly shouldnt happen. I am at a loss as to whether it is a GLib
> > > issues (unlikely I would have thought?) or its an lrmd bug.
> >
> > It's neither. It's bad usage of glib.
> >
> Is there anyone working on resolving this? I'm happy to help but dont
> have the time to debug further at present - not being a glib expert.
> I have other critical software projects to work on and just need
> something that works in this area!
>
> > > IMHO lrmd should NEVER hang!
> >
> > If you don't use upstart, it won't hang.
>
> Sadly I need upstart. Thats one reason I got into this situation in the
> first place!
>
> I currently have a production clustered server down because of this and
> the fact that ubuntu (I'm advised) have an inconsistently compiled set
> of HA components. Certaintly both lucid and maverick released packages
> leave defunct processes lying around and give highly unreliable
> operation :-(

The most plausible explanation is in this thread:
http://marc.info/?l=linux-ha-dev&m=128765996706209&w=2

The author didn't do anything yet about it, but hopefully it is
going to change.

Thanks,

Dejan

>
> Dave
> _______________________________________________________
> Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
> http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
> Home Page: http://linux-ha.org/
_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
On 14:18, Wed 24 Nov 10, Dejan Muhamedagic wrote:
>
> The most plausible explanation is in this thread:
> http://marc.info/?l=linux-ha-dev&m=128765996706209&w=2
>
Thanks for your quick response Dejan,

I understand what the thread says - which is why I posted my findings
on the list. As I said its 100% reproducable across both 32 and 64 bit versions
of ubuntu (server) so any proposed fixes should be quick to test.

I will dig a bit deeper and maybe try the g_thread_init() and g_type_init()
approaches myself. I am developing on separate VM's at present whilst my
production machine is limping along as a manually set up single node.

As regards solutions I have nothing to lose at this point other than
taking upstart out and recreating the init.d scripts I need as lsb RA's
rather than upstart RA's. The current scripts have been hijkacked and
replaced by calls to the upstart scripts thus losing their exits codes
upon which the system relies.

Dave


_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
U Sri, 24. 11. 2010., u 10:52 +0000, Dave Williams je napisao/la:

> I currently have a production clustered server down because of this and
> the fact that ubuntu (I'm advised) have an inconsistently compiled set
> of HA components. Certaintly both lucid and maverick released packages
> leave defunct processes lying around and give highly unreliable
> operation :-(

Can you elaborate on this?

OTOH, upstart plugin in ubuntu packages include one patch that wasn't
accepted upstream, cause of which upstart plugin works.

It's a known problem that upstream's version of cluster-glue doesn't
work yet with upstart and, pointing at my self, we still didn't test the
solution Dejan proposed. I'll do that today or tomorrow.

Dejan, sorry for not respoding sooner. I'm having hard time finding some
free time to work on this :(


_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
On 16:16, Wed 24 Nov 10, Ante Karamatić wrote:
> U Sri, 24. 11. 2010., u 10:52 +0000, Dave Williams je napisao/la:
>
> > I currently have a production clustered server down because of this and
> > the fact that ubuntu (I'm advised) have an inconsistently compiled set
> > of HA components. Certaintly both lucid and maverick released packages
> > leave defunct processes lying around and give highly unreliable
> > operation :-(
>
> Can you elaborate on this?
>
This is typical of the result of installing the pacemaker corosync cluster-glue
stack on otherwise reasonably clean machines.

root 20586 0.0 0.2 227056 5704 ? Ssl Nov17 4:39 /usr/sbin/corosync
root 20593 0.0 0.0 0 0 ? Z Nov17 0:00 \_ [stonithd] <defunct>
108 20594 0.0 0.2 80624 4636 ? S Nov17 0:05 \_ /usr/lib/heartbeat/cib
root 20595 0.0 0.0 0 0 ? Z Nov17 0:00 \_ [lrmd] <defunct>
108 20596 0.0 0.1 81568 2780 ? S Nov17 0:06 \_ /usr/lib/heartbeat/attrd
108 20597 0.0 0.0 0 0 ? Z Nov17 0:00 \_ [pengine] <defunct>
108 20598 0.0 0.1 87796 3060 ? S Nov17 0:05 \_ /usr/lib/heartbeat/crmd
108 20601 0.0 0.2 81016 5696 ? S Nov17 0:30 \_ /usr/lib/heartbeat/cib
root 20602 0.0 0.0 36424 1340 ? S Nov17 0:07 \_ /usr/lib/heartbeat/lrmd
108 20603 0.0 0.1 81568 3296 ? S Nov17 0:00 \_ /usr/lib/heartbeat/attrd
108 20604 0.0 0.1 81916 2796 ? S Nov17 0:00 \_ /usr/lib/heartbeat/pengine
root 20608 0.0 0.0 0 0 ? Z Nov17 0:00 \_ [corosync] <defunct>
root 20609 0.0 0.0 0 0 ? Z Nov17 0:00 \_ [corosync] <defunct>
root 20613 0.0 0.0 0 0 ? Z Nov17 0:00 \_ [corosync] <defunct>

It is the same irrespective of lucid/maverick cluster-glue-with-upstart/without-upstart
and 32/64bits. These are all on ubuntu-server not desktop.

> OTOH, upstart plugin in ubuntu packages include one patch that wasn't
> accepted upstream, cause of which upstart plugin works.
I appreciate the ubuntu cluster-glue package with upstart is new but sadly it wasnt
obvious there were problems with it on the various "announcements" I found.

I guess I shouldnt be so optimistic and current HA stack is quite a change from
original heartbeat based solution I had and so a lot to learn. You know what is
like when there is pressure to get things going (in our case a serious hardware
failure which required complete server replacement) - you end up understanding the
absolute minimum required to reach your (customer/bosses) goals.

>
> It's a known problem that upstream's version of cluster-glue doesn't
> work yet with upstart and, pointing at my self, we still didn't test the
> solution Dejan proposed. I'll do that today or tomorrow.

Maybe we can work in parallel on this. As I said I'm happy to assist where I can.
Whilst I am a seasoned software professional I am new to glib - so have a steep
learning curve to climb in that respect!

> Dejan, sorry for not respoding sooner. I'm having hard time finding some
> free time to work on this :(
Ditto :-(

>
>
> _______________________________________________________
> Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
> http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
> Home Page: http://linux-ha.org/
_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
On 16:16, Wed 24 Nov 10, Ante Karamatić wrote:
> U Sri, 24. 11. 2010., u 10:52 +0000, Dave Williams je napisao/la:
>
> > I currently have a production clustered server down because of this and
> > the fact that ubuntu (I'm advised) have an inconsistently compiled set
> > of HA components. Certaintly both lucid and maverick released packages
> > leave defunct processes lying around and give highly unreliable
> > operation :-(
>
> Can you elaborate on this?
>
> OTOH, upstart plugin in ubuntu packages include one patch that wasn't
> accepted upstream, cause of which upstart plugin works.
>
> It's a known problem that upstream's version of cluster-glue doesn't
> work yet with upstart and, pointing at my self, we still didn't test the
> solution Dejan proposed. I'll do that today or tomorrow.
>
> Dejan, sorry for not respoding sooner. I'm having hard time finding some
> free time to work on this :(
>

Adding the following patch

--- lrmd.c 2010-11-19 17:51:44.000000000 +0000
+++ ../../../lrmd.c 2010-11-24 20:40:49.351322794 +0000
@@ -1104,6 +1104,9 @@

register_pid(FALSE, sigterm_action);

+
+ g_thread_init(NULL);
+
/* load RA plugins */
PluginLoadingSystem = NewPILPluginUniv (HA_PLUGIN_DIR);
PILLoadPlugin(PluginLoadingSystem, "InterfaceMgr", "generic",
@@ -1172,10 +1175,10 @@
}

seems to fix the lrmadmin -C problem I reported!

I also tried compiling with G_ERRORCHECK_MUTEXES defined (before I applied the
above patch) but didnt see any extra error messages generated that would help
diagnose the problem.

Currently "crm configure verify" is reporting lrmd not running but I can successfully run
crm_verify -L -V
so I guess that must be a different issue.

I will carry on testing....

Dave
_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
> Adding the following patch
>
> --- lrmd.c 2010-11-19 17:51:44.000000000 +0000
> +++ ../../../lrmd.c 2010-11-24 20:40:49.351322794 +0000
> @@ -1104,6 +1104,9 @@
>
> register_pid(FALSE, sigterm_action);
>
> +
> + g_thread_init(NULL);
> +
> /* load RA plugins */
> PluginLoadingSystem = NewPILPluginUniv (HA_PLUGIN_DIR);
> PILLoadPlugin(PluginLoadingSystem, "InterfaceMgr", "generic",
>
Forgot the Makefile change that goes with it.

--- Makefile 2010-11-24 20:52:03.421323840 +0000
+++ ../../../Makefile 2010-11-24 20:38:11.571323583 +0000
@@ -142,7 +142,7 @@
LIBLTDL_DIR =
LIBNETCONFIG =
LIBOBJS = ${LIBOBJDIR}NoSuchFunctionName$U.o ${LIBOBJDIR}strlcpy$U.o ${LIBOBJDIR}strlcat$U.o
-LIBS = -lbz2 -lxml2 -lc -luuid -lrt -ldl -lglib-2.0 -lltdl
+LIBS = -lbz2 -lxml2 -lc -luuid -lrt -ldl -lglib-2.0 -lltdl -lgthread-2.0
LIBTOOL = $(SHELL) $(top_builddir)/libtool --tag=CC $(QUIET_LIBTOOL_OPTS)
LIPO =
LN_S = ln -s


Dave
_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
On Wed, Nov 24, 2010 at 2:18 PM, Dejan Muhamedagic <dejanmm@fastmail.fm> wrote:
> Hi,
>
> On Wed, Nov 24, 2010 at 10:52:23AM +0000, Dave Williams wrote:
>> On 10:35, Wed 24 Nov 10, Dejan Muhamedagic wrote:
>> > Hi,
>> >
>> > On Tue, Nov 23, 2010 at 11:03:33PM +0000, Dave Williams wrote:
>> > > Hi,
>> > > I have a problem that looks similar to that reported "possible deadlock
>> > > in lrmd" on 21st Oct
>> > >
>> > > When running lradmin -C to list classes the first time it comes back
>> > > immediately with the expected list e.g.
>> > >
>> > > root@node1:/home# lrmadmin -C
>> > > There are 5 RA classes supported:
>> > > lsb
>> > > ocf
>> > > stonith
>> > > upstart
>> > > heartbeat
>> > >
>> > > All subsequent attempts lrmadmin hangs and never comes back (you have to kill
>> > > with crtl-C). This is repeatable on all the machines I have tried it on.
>> >
>> > I'm afraid that this was to be expected.
>> Hi Dejan - thanks for your reply.
>>
>> I'm not sure which you imply:
>> a) Its known to be buggy?
>> b) Its working as designed?
>> I presume a).
>
> It is somewhat technical, but basically it's a).
>
>> .....
>>
>> > > On the surface the overall sequence makes sense but the hang doesnt and
>> > > clearly shouldnt happen. I am at a loss as to whether it is a GLib
>> > > issues (unlikely I would have thought?) or its an lrmd bug.
>> >
>> > It's neither. It's bad usage of glib.
>> >
>> Is there anyone working on resolving this?  I'm happy to help but dont
>> have the time to debug further at present - not being a glib expert.
>> I have other critical software projects to work on and just need
>> something that works in this area!
>>
>> > > IMHO lrmd should NEVER hang!
>> >
>> > If you don't use upstart, it won't hang.
>>
>> Sadly I need upstart. Thats one reason I got into this situation in the
>> first place!
>>
>> I currently have a production clustered server down because of this and
>> the fact that ubuntu (I'm advised) have an inconsistently compiled set
>> of HA components. Certaintly both lucid and maverick released packages
>> leave defunct processes lying around and give highly unreliable
>> operation :-(
>
> The most plausible explanation is in this thread:
> http://marc.info/?l=linux-ha-dev&m=128765996706209&w=2
>
> The author didn't do anything yet about it, but hopefully it is
> going to change.
>

Do I even want to know why the lrmd needs to be calling g_type_init() ?
_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
On Thu, Nov 25, 2010 at 09:47:51AM +0100, Andrew Beekhof wrote:
> On Wed, Nov 24, 2010 at 2:18 PM, Dejan Muhamedagic <dejanmm@fastmail.fm> wrote:
> > Hi,
> >
> > On Wed, Nov 24, 2010 at 10:52:23AM +0000, Dave Williams wrote:
> >> On 10:35, Wed 24 Nov 10, Dejan Muhamedagic wrote:
> >> > Hi,
> >> >
> >> > On Tue, Nov 23, 2010 at 11:03:33PM +0000, Dave Williams wrote:
> >> > > Hi,
> >> > > I have a problem that looks similar to that reported "possible deadlock
> >> > > in lrmd" on 21st Oct
> >> > >
> >> > > When running lradmin -C to list classes the first time it comes back
> >> > > immediately with the expected list e.g.
> >> > >
> >> > > root@node1:/home# lrmadmin -C
> >> > > There are 5 RA classes supported:
> >> > > lsb
> >> > > ocf
> >> > > stonith
> >> > > upstart
> >> > > heartbeat
> >> > >
> >> > > All subsequent attempts lrmadmin hangs and never comes back (you have to kill
> >> > > with crtl-C). This is repeatable on all the machines I have tried it on.
> >> >
> >> > I'm afraid that this was to be expected.
> >> Hi Dejan - thanks for your reply.
> >>
> >> I'm not sure which you imply:
> >> a) Its known to be buggy?
> >> b) Its working as designed?
> >> I presume a).
> >
> > It is somewhat technical, but basically it's a).
> >
> >> .....
> >>
> >> > > On the surface the overall sequence makes sense but the hang doesnt and
> >> > > clearly shouldnt happen. I am at a loss as to whether it is a GLib
> >> > > issues (unlikely I would have thought?) or its an lrmd bug.
> >> >
> >> > It's neither. It's bad usage of glib.
> >> >
> >> Is there anyone working on resolving this?  I'm happy to help but dont
> >> have the time to debug further at present - not being a glib expert.
> >> I have other critical software projects to work on and just need
> >> something that works in this area!
> >>
> >> > > IMHO lrmd should NEVER hang!
> >> >
> >> > If you don't use upstart, it won't hang.
> >>
> >> Sadly I need upstart. Thats one reason I got into this situation in the
> >> first place!
> >>
> >> I currently have a production clustered server down because of this and
> >> the fact that ubuntu (I'm advised) have an inconsistently compiled set
> >> of HA components. Certaintly both lucid and maverick released packages
> >> leave defunct processes lying around and give highly unreliable
> >> operation :-(
> >
> > The most plausible explanation is in this thread:
> > http://marc.info/?l=linux-ha-dev&m=128765996706209&w=2
> >
> > The author didn't do anything yet about it, but hopefully it is
> > going to change.
> >
>
> Do I even want to know why the lrmd needs to be calling g_type_init() ?

Probably not...

So that it can initialize some stuff _before_ using glib. When
the upstart plugin invokes g_type_ it's already too late.

Thanks,

Dejan
_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
On Thu, Nov 25, 2010 at 10:35 AM, Dejan Muhamedagic <dejanmm@fastmail.fm> wrote:
> On Thu, Nov 25, 2010 at 09:47:51AM +0100, Andrew Beekhof wrote:
>> On Wed, Nov 24, 2010 at 2:18 PM, Dejan Muhamedagic <dejanmm@fastmail.fm> wrote:
>> > Hi,
>> >
>> > On Wed, Nov 24, 2010 at 10:52:23AM +0000, Dave Williams wrote:
>> >> On 10:35, Wed 24 Nov 10, Dejan Muhamedagic wrote:
>> >> > Hi,
>> >> >
>> >> > On Tue, Nov 23, 2010 at 11:03:33PM +0000, Dave Williams wrote:
>> >> > > Hi,
>> >> > > I have a problem that looks similar to that reported "possible deadlock
>> >> > > in lrmd" on 21st Oct
>> >> > >
>> >> > > When running lradmin -C to list classes the first time it comes back
>> >> > > immediately with the expected list e.g.
>> >> > >
>> >> > > root@node1:/home# lrmadmin -C
>> >> > > There are 5 RA classes supported:
>> >> > > lsb
>> >> > > ocf
>> >> > > stonith
>> >> > > upstart
>> >> > > heartbeat
>> >> > >
>> >> > > All subsequent attempts lrmadmin hangs and never comes back (you have to kill
>> >> > > with crtl-C). This is repeatable on all the machines I have tried it on.
>> >> >
>> >> > I'm afraid that this was to be expected.
>> >> Hi Dejan - thanks for your reply.
>> >>
>> >> I'm not sure which you imply:
>> >> a) Its known to be buggy?
>> >> b) Its working as designed?
>> >> I presume a).
>> >
>> > It is somewhat technical, but basically it's a).
>> >
>> >> .....
>> >>
>> >> > > On the surface the overall sequence makes sense but the hang doesnt and
>> >> > > clearly shouldnt happen. I am at a loss as to whether it is a GLib
>> >> > > issues (unlikely I would have thought?) or its an lrmd bug.
>> >> >
>> >> > It's neither. It's bad usage of glib.
>> >> >
>> >> Is there anyone working on resolving this?  I'm happy to help but dont
>> >> have the time to debug further at present - not being a glib expert.
>> >> I have other critical software projects to work on and just need
>> >> something that works in this area!
>> >>
>> >> > > IMHO lrmd should NEVER hang!
>> >> >
>> >> > If you don't use upstart, it won't hang.
>> >>
>> >> Sadly I need upstart. Thats one reason I got into this situation in the
>> >> first place!
>> >>
>> >> I currently have a production clustered server down because of this and
>> >> the fact that ubuntu (I'm advised) have an inconsistently compiled set
>> >> of HA components. Certaintly both lucid and maverick released packages
>> >> leave defunct processes lying around and give highly unreliable
>> >> operation :-(
>> >
>> > The most plausible explanation is in this thread:
>> > http://marc.info/?l=linux-ha-dev&m=128765996706209&w=2
>> >
>> > The author didn't do anything yet about it, but hopefully it is
>> > going to change.
>> >
>>
>> Do I even want to know why the lrmd needs to be calling g_type_init() ?
>
> Probably not...
>
> So that it can initialize some stuff _before_ using glib. When
> the upstart plugin invokes g_type_ it's already too late.

Oh, the upstart API uses g_type_* ?
/me is (more) afraid to look at the code now - the whole g_object
concept is an abomination, and the code is worse.
_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
>
> Adding the following patch
>
> --- lrmd.c 2010-11-19 17:51:44.000000000 +0000
> +++ ../../../lrmd.c 2010-11-24 20:40:49.351322794 +0000
> @@ -1104,6 +1104,9 @@
>
> register_pid(FALSE, sigterm_action);
>
> +
> + g_thread_init(NULL);
> +
> /* load RA plugins */
> PluginLoadingSystem = NewPILPluginUniv (HA_PLUGIN_DIR);
> PILLoadPlugin(PluginLoadingSystem, "InterfaceMgr", "generic",
> @@ -1172,10 +1175,10 @@
> }
>
> seems to fix the lrmadmin -C problem I reported!
>
.....
> Currently "crm configure verify" is reporting lrmd not running but I can successfully run
> crm_verify -L -V
> so I guess that must be a different issue.
>
> I will carry on testing....

To follow up it appears that lrmd is aborting with the same error
message after executing both "crm configure verify" AND "lrmadmin -C"

Strace yields the following:

lrmd: [336]: debug: on_receive_cmd: the IPC to client [pid:342] disconnected.\n
\nGThread-ERROR **: Trying to recursively lock a mutex at 'unknown',
previously locked at 'unknown'\naborting...\n"

From the client's perspective lrmadmin never sees this as the daemon is
respawned (by crmd I presume) before you can manually execute the command again.

"crm configure verify" calls lrmadmin in a tight loop as it iterates over
cluster resources and so catches lrmd before it restarted and reports "not
running".

Looks like the g_thread_init() on its own isnt sufficient...

Dave

_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
> To follow up it appears that lrmd is aborting with the same error
> message after executing both "crm configure verify" AND "lrmadmin -C"
>
> Strace yields the following:
>
> lrmd: [336]: debug: on_receive_cmd: the IPC to client [pid:342] disconnected.\n
> \nGThread-ERROR **: Trying to recursively lock a mutex at 'unknown',
> previously locked at 'unknown'\naborting...\n"
>
> >From the client's perspective lrmadmin never sees this as the daemon is
> respawned (by crmd I presume) before you can manually execute the command again.
>
> "crm configure verify" calls lrmadmin in a tight loop as it iterates over
> cluster resources and so catches lrmd before it restarted and reports "not
> running".
>
> Looks like the g_thread_init() on its own isnt sufficient...
>
But this is what Senko's patch (2444.diff) fixes - so with that added it cures
the abort in both situations above. Now time to look at his potential ref leak.

Dave


_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
Hi,

On Thu, Nov 25, 2010 at 10:51:56PM +0000, Dave Williams wrote:
> > To follow up it appears that lrmd is aborting with the same error
> > message after executing both "crm configure verify" AND "lrmadmin -C"
> >
> > Strace yields the following:
> >
> > lrmd: [336]: debug: on_receive_cmd: the IPC to client [pid:342] disconnected.\n
> > \nGThread-ERROR **: Trying to recursively lock a mutex at 'unknown',
> > previously locked at 'unknown'\naborting...\n"
> >
> > >From the client's perspective lrmadmin never sees this as the daemon is
> > respawned (by crmd I presume) before you can manually execute the command again.
> >
> > "crm configure verify" calls lrmadmin in a tight loop as it iterates over
> > cluster resources and so catches lrmd before it restarted and reports "not
> > running".
> >
> > Looks like the g_thread_init() on its own isnt sufficient...
> >
> But this is what Senko's patch (2444.diff) fixes - so with that added it cures
> the abort in both situations above. Now time to look at his potential ref leak.

That patch doesn't cure the cause, just works around it. lrmd
would just keep accumulating open IPC sockets.

Thanks,

Dejan

> Dave
>
>
> _______________________________________________________
> Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
> http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
> Home Page: http://linux-ha.org/
_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
> > But this is what Senko's patch (2444.diff) fixes - so with that added it cures
> > the abort in both situations above. Now time to look at his potential ref leak.
>
> That patch doesn't cure the cause, just works around it. lrmd
> would just keep accumulating open IPC sockets.
>
> Thanks,
>
> Dejan
>
I apprectiate that - I was simply reporting the removal of fault symptoms with
the patch applied. It shows we are working in the right area. I need to
better understand the overall code to see if I can deduce the root cause
and hence come up with a better fix. It doesnt look like a particularly
easy thing to debug.

Dave
_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
Hi all,

Any updates on this issue?

On Fri, Nov 26, 2010 at 9:27 AM, Dave Williams <
dave@opensourcesolutions.co.uk> wrote:

> > > But this is what Senko's patch (2444.diff) fixes - so with that added
> it cures
> > > the abort in both situations above. Now time to look at his potential
> ref leak.
> >
> > That patch doesn't cure the cause, just works around it. lrmd
> > would just keep accumulating open IPC sockets.
> >
> > Thanks,
> >
> > Dejan
> >
> I apprectiate that - I was simply reporting the removal of fault symptoms
> with
> the patch applied. It shows we are working in the right area. I need to
> better understand the overall code to see if I can deduce the root cause
> and hence come up with a better fix. It doesnt look like a particularly
> easy thing to debug.
>
> Dave
> _______________________________________________________
> Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
> http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
> Home Page: http://linux-ha.org/
>



--
Andres Rodriguez (RoAkSoAx)
Ubuntu MOTU Developer
Systems Engineer
Re: possible deadlock in lrmd? [ In reply to ]
On 03.11.2010 11:34, Dejan Muhamedagic wrote:

> Any news here?

Yes. I know, it's been a while...

At the time patch '2444'[1] was provided, glib had a bug[2] that was
resolved few months later. 2444 patch did resolve the deadlock
introduced by glib, but it also introduced a socket leak when lrmadmin
was used.

By applying glib patch and removing 2444 patch, everything gets fixed.
To make things short: *No changes are required for cluster-glue*

For those using 10.04 and 10.10, until fix gets to the archive, I
suggest updating glib from this PPA:

https://launchpad.net/~ivoks/+archive/glib

Most recent Cluster stack can, as always, be acquired at:

https://launchpad.net/~ubuntu-ha-maintainers/+archive/ppa

Best regards

[1] http://www.init.hr/dev/cluster/patches/2444.diff
[2] http://tinyurl.com/ch9jddd
_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/
Re: possible deadlock in lrmd? [ In reply to ]
On Wed, Nov 09, 2011 at 09:26:09AM +0100, Ante Karamatic wrote:
> On 03.11.2010 11:34, Dejan Muhamedagic wrote:
>
> > Any news here?
>
> Yes. I know, it's been a while...
>
> At the time patch '2444'[1] was provided, glib had a bug[2] that was
> resolved few months later. 2444 patch did resolve the deadlock
> introduced by glib, but it also introduced a socket leak when lrmadmin
> was used.

So, after all it was a glib issue.

> By applying glib patch and removing 2444 patch, everything gets fixed.
> To make things short: *No changes are required for cluster-glue*

Excellent news.

Glad that we can close this chapter.

Cheers,

Dejan

> For those using 10.04 and 10.10, until fix gets to the archive, I
> suggest updating glib from this PPA:
>
> https://launchpad.net/~ivoks/+archive/glib
>
> Most recent Cluster stack can, as always, be acquired at:
>
> https://launchpad.net/~ubuntu-ha-maintainers/+archive/ppa
>
> Best regards
>
> [1] http://www.init.hr/dev/cluster/patches/2444.diff
> [2] http://tinyurl.com/ch9jddd
> _______________________________________________________
> Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
> http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
> Home Page: http://linux-ha.org/
_______________________________________________________
Linux-HA-Dev: Linux-HA-Dev@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha-dev
Home Page: http://linux-ha.org/