[ClusterLabs] [Problem] The `attrd` process may encounter an IPC communication error (`pcmk__ipc_send_iov`), rendering it unable to communicate and triggering a restart.

[Chris Lumens]

>> So the question is:  what's controld doing that's keeping it from responding to attrd?
> 
> Looking at the subsequent logs, `attrd_updater` from the `ping` resource is failing, which suggests that `attrd` is not responding.
> `controld`(4671) itself appears to be running.

Right, I think attrd_updater failing is a symptom of the same problem. 
It fails because pacemaker-attrd isn't responding, because 
pacemaker-attrd is too busy trying to send something to 
pacemaker-controld and keeps getting told EAGAIN.

What pacemaker-attrd is doing is calling pcmk__ipc_send_xml -> 
pcmk__ipc_send_iov on something that's not an event.  It's getting 
EAGAIN in response, and just loops forever.

attrd_updater fails because pacemaker-attrd is never returning to the 
mainloop to process any incoming messages.  That's what happens with 
pacemakerd too.  It keeps asking pacemaker-attrd if it's alive, but it 
never gets a chance to process that incoming message.

That's why I am wondering what's going on with controld.  It's busy 
doing something that's keeping it from replying to attd.

> As previously mentioned, the setup consists of 5 nodes, with approximately 40 resources (such as "dummy" resources). Note that resource placement is determined based on utilization.

This doesn't seem like an especially high number of nodes or resources, 
certainly not as many as I've had to set up to cause these kinds of IPC 
problems in the past.

> Furthermore, this issue is extremely difficult to reproduce; under normal circumstances, this error does not occur.

I think the next step in figuring this out is (1) what is attrd trying 
to send to controld? and (2) what is controld busy doing?

I think (1) will help us narrow down how attrd gets there and what code 
paths the controld side is going to use.  Unfortunately, we don't log 
what we're going to send in pcmk__ipc_send_iov, only what we have 
successfully sent 
(https://github.com/ClusterLabs/pacemaker/blob/main/lib/common/ipc_server.c#L793). 
  We're not successfully sending here, so that's not really helpful.

Luckily, I think this has to go through pcmk__ipc_send_xml and attrd 
calls that in attrd_handle_request, which does log what it's about to 
send 
(https://github.com/ClusterLabs/pacemaker/blob/main/daemons/attrd/attrd_messages.c#L281).

So, add attrd_messages.c to PCMK_trace_files.

Note that it could also be calling it via pcmk__ipc_send_ack_as, which 
does also log.  You could add ipc_server.c as well.  This will generate 
an awful lot of logging.

As far as (2), I'm really not sure what to do to figure that out. 
pacemaker-controld doesn't log anything between 07:15:03.108 and 
07:15:38.076, which is a really long time.

The last thing it does is call handle_shutdown_request, which calls 
update_attrd, and that seems really suspicious to me.  Prior to this, 
pacemaker-attrd hasn't logged anything in a couple minutes.

I guess I might add controld_messages.c to the trace logs as well to see 
what message it's constructing.  I'm also starting to wonder if e4389467 
is involved here too.

Sorry this is so rambling - I'm kind of typing it as I'm exploring the code.

- Chris