View Issue Details

IDProjectCategoryView StatusLast Update
0000156Pgpool-IIBugpublic2016-01-17 22:27
ReporterharukatAssigned Tot-ishii 
PrioritynormalSeverityminorReproducibilitysometimes
Status resolvedResolutionopen 
Product Version3.4.0 
Target VersionFixed in Version 
Summary0000156: Pgpool reload during high load causes the fatal error
DescriptionPgpool reload during high load causes the fatal error.

Nov 13 14:42:10 host01 pgpool_xxxx[80744]: [4427-1] 2015-11-13 14:42:10 80744 LOG: reload config files.
Nov 13 14:42:10 host01 pgpool_xxxx[80744]: [4428-1] 2015-11-13 14:42:10 80744 LOG: initializing pool configuration: backend weight for backend:1 changed from 1.000000 to 100.000000
Nov 13 14:42:10 host01 pgpool_xxxx[80744]: [4428-2] 2015-11-13 14:42:10 80744 DETAIL: This change will be effective from next client session
Nov 13 14:42:10 host01 pgpool_xxxx[83077]: [2218-1] 2015-11-13 14:42:10 83077 LOG: reloading config file
Nov 13 14:42:16 host01 pgpool_xxxx[84339]: [3780-1] 2015-11-13 14:42:16 84339 FATAL: failed to read kind from backend
Nov 13 14:42:16 host01 pgpool_xxxx[84339]: [3780-2] 2015-11-13 14:42:16 84339 DETAIL: couldn't find first node. All backend down?

Our pool_get_config() chnages "backend_desc" on shared memory without
an exclusive lock. Pgpool child process may read invalid "backend_desc"
and get an error.
TagsNo tags attached.

Activities

t-ishii

2015-11-25 10:57

developer   ~0000598

Not clear which configuration items did you change?

harukat

2015-12-04 19:01

developer   ~0000602

When any kind of item is changed, this occurs (even reloadable one).

harukat

2015-12-04 19:05

developer   ~0000603

In addition, it occurs even in a case except the backend related setting.

t-ishii

2015-12-07 12:08

developer   ~0000604

Works fine for me. What I did was:

Run pgpool_setup.
Edit pgpool.conf to make "log_per_node_statement" commented out.
Run pgbench as "pgbench -p 11000 -S -c 10 -T 3600".
Edit pgpool.conf to make "log_per_node_statement" enabled.
Run pgpool reload using "pgpool_reload" script.
Check to see if per node statement logs appear.

harukat

2015-12-20 19:10

developer   ~0000620

This was reproduced in our customer's production environment.
It has many CPU core and over 900 frontends.

pool_get_config() always sets "pool_config->backend_desc->num_backends"
to 0 first and count it up subsequently, though this variable is in the
shared memory.

---
int pool_get_config(char *confpath, POOL_CONFIG_CONTEXT context)
....(snip)....
   pool_config->backend_desc->num_backends = 0;
   total_weight = 0.0;

    for (i=0;i<MAX_CONNECTION_SLOTS;i++)
    {
        /* port number == 0 indicates that this server is out of use */
        if (BACKEND_INFO(i).backend_port == 0)
        {
            clear_host_entry(i);
        }

        else
        {
            total_weight += BACKEND_INFO(i).unnormalized_weight;
            pool_config->backend_desc->num_backends = i+1;

t-ishii

2015-12-25 14:43

developer   ~0000623

Got it. However I don't think locking the variable solves the problem. There are so many places where child process do something like:

for (i=0;i<pool_config->backend_desc->num_backends;i++)
{
      :
      :
}

We have to lock the whole for loop which will hurt concurrency according to your idea. Probably we have to have a process local cache variable something like my_backend_status.

harukat

2015-12-29 11:18

developer   ~0000628

I think we must remove unnecessary zeroing num_backends at least.

harukat

2015-12-29 11:18

developer  

V3_4_STABLE.pool_get_config.diff (1,306 bytes)
diff --git a/src/config/pool_config.l b/src/config/pool_config.l
index 78ee2ae..926d5f8 100644
--- a/src/config/pool_config.l
+++ b/src/config/pool_config.l
@@ -440,6 +440,7 @@ int pool_get_config(char *confpath, POOL_CONFIG_CONTEXT context)
 	int i;
 	int error_level;
     bool log_destination_changed = false;
+	int local_num_backends;
 #ifdef USE_MEMCACHED
 	bool use_memcached = true;
 #else
@@ -3329,7 +3330,7 @@ int pool_get_config(char *confpath, POOL_CONFIG_CONTEXT context)
 		}
 	}
 
-	pool_config->backend_desc->num_backends = 0;
+	local_num_backends = 0;
 	total_weight = 0.0;
 
 	for (i=0;i<MAX_CONNECTION_SLOTS;i++)
@@ -3343,7 +3344,7 @@ int pool_get_config(char *confpath, POOL_CONFIG_CONTEXT context)
 		else
 		{
 			total_weight += BACKEND_INFO(i).unnormalized_weight;
-			pool_config->backend_desc->num_backends = i+1;
+			local_num_backends = i+1;
 			
 			/* initialize backend_hostname with a default socket path if empty */
 			if (*(BACKEND_INFO(i).backend_hostname) == '\0')
@@ -3356,6 +3357,8 @@ int pool_get_config(char *confpath, POOL_CONFIG_CONTEXT context)
 			}
 		}	
 	}
+	if (local_num_backends != pool_config->backend_desc->num_backends)
+			pool_config->backend_desc->num_backends = local_num_backends;
 
 	ereport(DEBUG1,
 		(errmsg("initializing pool configuration"),

harukat

2015-12-29 11:19

developer   ~0000629

I attached V3_4_STABLE.pool_get_config.diff

t-ishii

2015-12-29 11:30

developer   ~0000630

This doesn't work because child process will be confused while looping for pool_config->backend_desc->num_backends.

As I said, pgpool child should look into local cache of pool_config->backend_desc->num_backends, and update the cache whenever it feels convenient (hint: check_restart_request() in child.c).

t-ishii

2016-01-17 22:26

developer   ~0000636

After thinking more, I reached a conclusion that we don't need locking, instead we use a atomic variable (sig_atomic_t) and it's enough for the problem.
Fix committed. Thanks.

Issue History

Date Modified Username Field Change
2015-11-16 14:34 harukat New Issue
2015-11-25 10:57 t-ishii Note Added: 0000598
2015-11-25 10:57 t-ishii Assigned To => t-ishii
2015-11-25 10:57 t-ishii Status new => feedback
2015-12-04 19:01 harukat Note Added: 0000602
2015-12-04 19:01 harukat Status feedback => assigned
2015-12-04 19:05 harukat Note Added: 0000603
2015-12-07 12:08 t-ishii Note Added: 0000604
2015-12-07 12:09 t-ishii Status assigned => feedback
2015-12-20 19:10 harukat Note Added: 0000620
2015-12-20 19:10 harukat Status feedback => assigned
2015-12-25 14:43 t-ishii Note Added: 0000623
2015-12-29 11:18 harukat Note Added: 0000628
2015-12-29 11:18 harukat File Added: V3_4_STABLE.pool_get_config.diff
2015-12-29 11:19 harukat Note Added: 0000629
2015-12-29 11:30 t-ishii Note Added: 0000630
2016-01-17 22:26 t-ishii Note Added: 0000636
2016-01-17 22:27 t-ishii Status assigned => resolved