[pgpool-hackers: 4131] Re: invalid degenerate backend request, node id : 2 status: [2] is not valid for failover

[anirudh.goel at cern.ch]

Hello Tatsuo

Thank you so much for the explanation. I understand the problem but same as you, cannot understand the reason behind it. The same variable 'BACKEND_INFO(i).backend_status’ cannot have 2 different values. Maybe the VALID_BACKEND macro is false due to other checks that it has in its if else blocks. I am not sure. I will try to have a look.

As for the reproducibility, you are right, in the past few months of development and testing, I have only seen this issue a couple times. Earlier, I thought it was something that I missed in the config but now that my setup is almost production ready, I opened this ticket for help. It is really difficult to reproduce but I currently have a setup running where this problem is persistent. I have tried by turning that replica off and on several times and it connects back to the cluster when it's up but I see the same error when it’s down.

So, if you prefer I can help you investigate more on this by sharing some detailed logs and config options from my setup.

Even though this issue comes up rarely, but this is important for me to resolve because my setup uses synchronous replication and if both of my replicas are down, I convert the replication mode from sync to async in the failover script. But if this bug shows up, then the failover script is not executed when the last replica goes down and my queries hang forever because they do not have a replica committing transactions in synchronous mode.

So, if I can help you debug this by providing any logs or config or a direct access to my setup over a Zoom call, that’d be really great for me. Please let me know if this works for you.

Thank you

Anirudh
On 19 Feb 2022, 2:33 AM +0100, Tatsuo Ishii <ishii at sraoss.co.jp>, wrote:
> > Hello
> >
> > I had the following setup:
> > 1 pgpool: 4.2.2
> > 3 postgres nodes (all 12.5) - 1 primary, 2 replicas
> >
> > I turned off both replicas one after the other with a difference of a couple seconds. Failover was performed for one of the replicas but not for the other. For the second replica the healthcheck keeps on failing but it just keeps on performing the healthcheck in an infinite loop. When pgpool attempts the failover of the second replica, I see this error in the logs:
> >
> > invalid degenerate backend request, node id : 2 status: [2] is not valid for failover
> >
> > As far as I understand, status [2] is up, so the failover should be performed. Here¢s a snippet of the logs:
>
> You are right. Problem is, two different internal APIs which both extract the status do not agree.
> The error messages comes from here:
> src/main/pool_internal_comms.c: degenerate_backend_set_ex()
>
> for (i = 0; i < count; i++)
> {
> if (node_id_set[i] < 0 || node_id_set[i] >= MAX_NUM_BACKENDS ||
> (!VALID_BACKEND(node_id_set[i]) && BACKEND_INFO(node_id_set[i]).quarantine == false))
> {
> if (node_id_set[i] < 0 || node_id_set[i] >= MAX_NUM_BACKENDS)
> ereport(elevel,
> (errmsg("invalid degenerate backend request, node id: %d is out of range. node id must be between [0 and %d]"
> ,node_id_set[i], MAX_NUM_BACKENDS)));
> else
> ereport(elevel,
> (errmsg("invalid degenerate backend request, node id : %d status: [%d] is not valid for failover"
> ,node_id_set[i], BACKEND_INFO(node_id_set[i]).backend_status)));
>
> I think VALID_BACKEND(node_id_set[i]) returned false
> here. VALID_BACKEND returns false if the backend status in the shared
> memory area is neither 1 (waiting for connection) nor 2 (up and
> running). However BACKEND_INFO(node_id_set[i]).backend_status says
> backend_status is actually 2 (up and running). The strange things is,
> both VALID_BACKEND and BACKEND_INFO(node_id_set[i]).backend_status
> look into the same shared memory area. Let me explain.
>
> VALID_BACKEND is a macron to be expanded as:
>
> #define VALID_BACKEND(backend_id) \
> ((RAW_MODE && (backend_id) == REAL_MAIN_NODE_ID) || \
> (pool_is_node_to_be_sent_in_current_query((backend_id)) && \
> ((*(my_backend_status[(backend_id)]) == CON_UP) || \
> (*(my_backend_status[(backend_id)]) == CON_CONNECT_WAIT))))
>
> Since you are running pgpool in other than RAW_MODE, the macro first
> checks if pool_is_node_to_be_sent_in_current_query((backend_id)
> returns true. Here is the portion of the code (defined in
> src/context/pool_query_context.c).
>
> bool
> pool_is_node_to_be_sent_in_current_query(int node_id)
> {
> POOL_SESSION_CONTEXT *sc;
>
> if (RAW_MODE)
> return node_id == REAL_MAIN_NODE_ID;
>
> As I said earlier, RAW_MODE returns false. So it executes next line:
>
> sc = pool_get_session_context(true);
> if (!sc)
> return true;
>
> pool_get_session_context() returns false and this function returns
> true because health check process did not use "sessoion context". The
> session context only exists on pgpool child process which deal with
> user connections.
>
> Then the macro checks local variable:
> my_backend_status[(backend_id). The local variable is initialized at
> the pgpool main process (src/main/pgpool_main.c) and inherited via
> fork() to the health check process.
>
> /*
> * Initialize backend status area. From now on, VALID_BACKEND macro can be
> * used. (get_next_main_node() uses VALID_BACKEND)
> */
>
> for (i = 0; i < MAX_NUM_BACKENDS; i++)
> {
> my_backend_status[i] = &(BACKEND_INFO(i).backend_status);
> }
>
> As you can see actually my_backend_status stores the pointer to
> BACKEND_INFO(i).backend_status. So *(my_backend_status[(backend_id)
> should be same as BACKEND_INFO(backend_id).backend_status.
>
> However, as I said earlier, it seems they seem to disagree. At this
> point I can't think of any explanation for this.
>
> How often do you see this problem? It's reliably reproduced?
> I was not able to reproduce this so far.
>
> Best reagards,
> --
> Tatsuo Ishii
> SRA OSS, Inc. Japan
> English: http://www.sraoss.co.jp/index_en.php
> Japanese:http://www.sraoss.co.jp
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.pgpool.net/pipermail/pgpool-hackers/attachments/20220220/5219290c/attachment.htm>