View Issue Details

IDProjectCategoryView StatusLast Update
0000068Pgpool-IIBugpublic2013-08-05 22:01
ReporterharukatAssigned Tot-ishii 
PrioritynormalSeveritymajorReproducibilityalways
Status resolvedResolutionopen 
Product Version 
Target VersionFixed in Version 
Summary0000068: child process termination with sigabort when memory_cache_enabled = on
DescriptionThis reproducing program get the following messages
(when pgpool run on same shell session).

*** glibc detected *** pgpool: postgres postgres 127.0.0.1(42074) idle in transaction: corrupted double-linked list: 0x00000000012a0f50 ***
======= Backtrace: =========
/lib64/libc.so.6[0x3b736760e6]
/lib64/libc.so.6[0x3b73678f01]
pgpool: postgres postgres 127.0.0.1(42074) idle in transaction[0x44d877]
pgpool: postgres postgres 127.0.0.1(42074) idle in transaction[0x44d8e0]
pgpool: postgres postgres 127.0.0.1(42074) idle in transaction[0x44de0f]
pgpool: postgres postgres 127.0.0.1(42074) idle in transaction[0x4502cc]
pgpool: postgres postgres 127.0.0.1(42074) idle in transaction[0x448b7e]
pgpool: postgres postgres 127.0.0.1(42074) idle in transaction[0x4498ae]
pgpool: postgres postgres 127.0.0.1(42074) idle in transaction[0x41ba95]
pgpool: postgres postgres 127.0.0.1(42074) idle in transaction[0x40b118]
pgpool: postgres postgres 127.0.0.1(42074) idle in transaction[0x4049b5]
pgpool: postgres postgres 127.0.0.1(42074) idle in transaction[0x405f7a]
pgpool: postgres postgres 127.0.0.1(42074) idle in transaction[0x4080f4]
/lib64/libc.so.6(__libc_start_main+0xfd)[0x3b7361ecdd]
pgpool: postgres postgres 127.0.0.1(42074) idle in transaction[0x403cf9]
======= Memory map: ========
00400000-004f1000 r-xp 00000000 fd:02 3021730 /home/postgres/pgsql/pgpool-II-3.2.5/bin/pgpool
006f0000-006f2000 rw-p 000f0000 fd:02 3021730 /home/postgres/pgsql/pgpool-II-3.2.5/bin/pgpool
006f2000-00711000 rw-p 00000000 00:00 0
01270000-012af000 rw-p 00000000 00:00 0
012af000-012dd000 rw-p 00000000 00:00 0
3b73200000-3b73220000 r-xp 00000000 fd:00 2097154 /lib64/ld-2.12.so
3b7341f000-3b73420000 r--p 0001f000 fd:00 2097154 /lib64/ld-2.12.so
3b73420000-3b73421000 rw-p 00020000 fd:00 2097154 /lib64/ld-2.12.so
3b73421000-3b73422000 rw-p 00000000 00:00 0
3b73600000-3b7378a000 r-xp 00000000 fd:00 2097180 /lib64/libc-2.12.so
3b7378a000-3b73989000 ---p 0018a000 fd:00 2097180 /lib64/libc-2.12.so
3b73989000-3b7398d000 r--p 00189000 fd:00 2097180 /lib64/libc-2.12.so
3b7398d000-3b7398e000 rw-p 0018d000 fd:00 2097180 /lib64/libc-2.12.so
3b7398e000-3b73993000 rw-p 00000000 00:00 0
3b73a00000-3b73a83000 r-xp 00000000 fd:00 2097246 /lib64/libm-2.12.so
3b73a83000-3b73c82000 ---p 00083000 fd:00 2097246 /lib64/libm-2.12.so
3b73c82000-3b73c83000 r--p 00082000 fd:00 2097246 /lib64/libm-2.12.so
3b73c83000-3b73c84000 rw-p 00083000 fd:00 2097246 /lib64/libm-2.12.so
3b73e00000-3b73e10000 r-xp 00000000 fd:00 2903447 /usr/lib64/libmemcached.so.2.0.0
3b73e10000-3b7400f000 ---p 00010000 fd:00 2903447 /usr/lib64/libmemcached.so.2.0.0
3b7400f000-3b74010000 rw-p 0000f000 fd:00 2903447 /usr/lib64/libmemcached.so.2.0.0
3b74200000-3b74217000 r-xp 00000000 fd:00 2097204 /lib64/libpthread-2.12.so
3b74217000-3b74417000 ---p 00017000 fd:00 2097204 /lib64/libpthread-2.12.so
3b74417000-3b74418000 r--p 00017000 fd:00 2097204 /lib64/libpthread-2.12.so
3b74418000-3b74419000 rw-p 00018000 fd:00 2097204 /lib64/libpthread-2.12.so
3b74419000-3b7441d000 rw-p 00000000 00:00 0
3b75600000-3b75616000 r-xp 00000000 fd:00 2097256 /lib64/libresolv-2.12.so
3b75616000-3b75816000 ---p 00016000 fd:00 2097256 /lib64/libresolv-2.12.so
3b75816000-3b75817000 r--p 00016000 fd:00 2097256 /lib64/libresolv-2.12.so
3b75817000-3b75818000 rw-p 00017000 fd:00 2097256 /lib64/libresolv-2.12.so
3b75818000-3b7581a000 rw-p 00000000 00:00 0
3b7e200000-3b7e25d000 r-xp 00000000 fd:00 2097408 /lib64/libfreebl3.so
3b7e25d000-3b7e45c000 ---p 0005d000 fd:00 2097408 /lib64/libfreebl3.so
3b7e45c000-3b7e45d000 r--p 0005c000 fd:00 2097408 /lib64/libfreebl3.so
3b7e45d000-3b7e45e000 rw-p 0005d000 fd:00 2097408 /lib64/libfreebl3.so
3b7e45e000-3b7e462000 rw-p 00000000 00:00 0
3b7e600000-3b7e607000 r-xp 00000000 fd:00 2097410 /lib64/libcrypt-2.12.so
3b7e607000-3b7e807000 ---p 00007000 fd:00 2097410 /lib64/libcrypt-2.12.so
3b7e807000-3b7e808000 r--p 00007000 fd:00 2097410 /lib64/libcrypt-2.12.so
3b7e808000-3b7e809000 rw-p 00008000 fd:00 2097410 /lib64/libcrypt-2.12.so
3b7e809000-3b7e837000 rw-p 00000000 00:00 0
3b7f600000-3b7f616000 r-xp 00000000 fd:00 2097262 /lib64/libgcc_s-4.4.6-20110824.so.1
3b7f616000-3b7f815000 ---p 00016000 fd:00 2097262 /lib64/libgcc_s-4.4.6-20110824.so.1
3b7f815000-3b7f816000 rw-p 00015000 fd:00 2097262 /lib64/libgcc_s-4.4.6-20110824.so.1
3b87200000-3b87216000 r-xp 00000000 fd:00 2097489 /lib64/libnsl-2.12.so
3b87216000-3b87415000 ---p 00016000 fd:00 2097489 /lib64/libnsl-2.12.so
3b87415000-3b87416000 r--p 00015000 fd:00 2097489 /lib64/libnsl-2.12.so
3b87416000-3b87417000 rw-p 00016000 fd:00 2097489 /lib64/libnsl-2.12.so
3b87417000-3b87419000 rw-p 00000000 00:00 0
7fd2ec39a000-7fd2ec8af000 rw-p 00000000 00:00 0
7fd2ec8af000-7fd2ec8d1000 rw-s 00000000 00:04 1474566 /SYSV00000000 (deleted)
7fd2ec8d1000-7fd2ec8dd000 r-xp 00000000 fd:00 2097181 /lib64/libnss_files-2.12.so
7fd2ec8dd000-7fd2ecadd000 ---p 0000c000 fd:00 2097181 /lib64/libnss_files-2.12.so
7fd2ecadd000-7fd2ecade000 r--p 0000c000 fd:00 2097181 /lib64/libnss_files-2.12.so
7fd2ecade000-7fd2ecadf000 rw-p 0000d000 fd:00 2097181 /lib64/libnss_files-2.12.so
7fd2ecaf8000-7fd2ecafb000 rw-p 00000000 00:00 0
7fd2ecafb000-7fd2ecafd000 r-xp 00000000 fd:00 2097250 /lib64/libdl-2.12.so
7fd2ecafd000-7fd2eccfd000 ---p 00002000 fd:00 2097250 /lib64/libdl-2.12.so
7fd2eccfd000-7fd2eccfe000 r--p 00002000 fd:00 2097250 /lib64/libdl-2.12.so
7fd2eccfe000-7fd2eccff000 rw-p 00003000 fd:00 2097250 /lib64/libdl-2.12.so
7fd2eccff000-7fd2ecd02000 rw-p 00000000 00:00 0
7fd2ecd09000-7fd2ecd0a000 rw-s 00000000 00:04 1605642 /SYSV00000000 (deleted)
7fd2ecd0a000-7fd2ecd0b000 rw-s 00000000 00:04 1572873 /SYSV00000000 (deleted)
7fd2ecd0b000-7fd2ecd0c000 rw-s 00000000 00:04 1540104 /SYSV00000000 (deleted)
7fd2ecd0c000-7fd2ecd0d000 rw-s 00000000 00:04 1507335 /SYSV00000000 (deleted)
7fd2ecd0d000-7fd2ecd1b000 rw-s 00000000 00:04 1441797 /SYSV00000000 (deleted)
7fd2ecd1b000-7fd2ecd22000 r-xp 00000000 fd:02 3021840 /home/postgres/pgsql/pgpool-II-3.2.5/lib/libpcp.so.0.0.0
7fd2ecd22000-7fd2ecf22000 ---p 00007000 fd:02 3021840 /home/postgres/pgsql/pgpool-II-3.2.5/lib/libpcp.so.0.0.0
7fd2ecf22000-7fd2ecf23000 rw-p 00007000 fd:02 3021840 /home/postgres/pgsql/pgpool-II-3.2.5/lib/libpcp.so.0.0.0
7fd2ecf23000-7fd2ecf24000 rw-p 00000000 00:00 0
7fd2ecf24000-7fd2ecf48000 r-xp 00000000 fd:02 536886 /home/postgres/pgsql/9.1.9/lib/libpq.so.5.4
7fd2ecf48000-7fd2ed147000 ---p 00024000 fd:02 536886 /home/postgres/pgsql/9.1.9/lib/libpq.so.5.4
7fd2ed147000-7fd2ed14a000 rw-p 00023000 fd:02 536886 /home/postgres/pgsql/9.1.9/lib/libpq.so.5.4
7fd2ed14a000-7fd2ed14b000 rw-p 00000000 00:00 0
7fff1a06c000-7fff1a081000 rw-p 00000000 00:00 0 [stack]
7fff1a09a000-7fff1a09b000 r-xp 00000000 00:00 0 [vdso]
ffffffffff600000-ffffffffff601000 r-xp 00000000 00:00 0 [vsyscall]
jdbctest: ERROR: org.postgresql.util.PSQLException: バックエンドに送信中に、入出力エラーはが起こりました。
org.postgresql.util.PSQLException: バックエンドに送信中に、入出力エラーはが起こりました。
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:281)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:555)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:417)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:363)
        at jdbctest3.main(jdbctest3.java:38)
Caused by: java.net.SocketException: Connection reset
        at java.net.SocketInputStream.read(SocketInputStream.java:185)
        at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:143)
        at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:112)
        at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:71)
        at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:269)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1700)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255)
        ... 4 more
Steps To Reproducesimple reproduce program:
------
import java.sql.*;
import javax.sql.*;
import java.util.*;
import java.io.*;
public class jdbctest3 {
  public static void main(String[] args) {
    try {
      Properties prop = new Properties();
      prop.load(new FileInputStream("jdbctest.prop"));
      String url = prop.getProperty("jdbc.url");
      String user = prop.getProperty("jdbc.user");
      String pwd = prop.getProperty("jdbc.password");
      Connection conn = DriverManager.getConnection(url, user, pwd);
      conn.setAutoCommit(false);
      String sql_u = "UPDATE pgbench_accounts SET filler = 'x' WHERE aid = ?";
      String sql_s = "SELECT * FROM pgbench_accounts WHERE aid != ? LIMIT 100";
      PreparedStatement pst_u, pst_s;
      int aid = 1, c1 = 0, c2 = 0;
      ResultSet rs;
      String tmp;
      for (c1 = 0; c1 < 10 ; ++c1) {
        pst_u = conn.prepareStatement(sql_u);
        pst_s = conn.prepareStatement(sql_s);
        aid = (int) Math.floor(Math.random() * 10) + 1;
        pst_u.setInt(1, aid);
        pst_u.executeUpdate();
        for (c2 = 0; c2 < 10; ++c2) {
          aid = (int) Math.floor(Math.random() * 10) + 1;
          pst_s.setInt(1, aid);
          rs = pst_s.executeQuery();
          while (rs.next()) { tmp = rs.getString(4); }
          rs.close();
        }
        conn.commit();
        pst_u.close();
        pst_s.close();
      }
      conn.close();
    } catch (Exception e) {
      System.err.println("jdbctest: ERROR: " + e);
      e.printStackTrace();
      System.exit(1);
    }
  }
}
TagsNo tags attached.

Activities

t-ishii

2013-08-05 16:46

developer   ~0000310

Bug found and fix attached. If Bind is repeated after parse, same temp cache pointers are registered in the cache arrary and after the first temp cache pointer freed, subsequent attempt to free temp caches cause doulbe free.

t-ishii

2013-08-05 16:47

developer  

pool_memqcache.c.patch (2,777 bytes)
diff --git a/pool_memqcache.c b/pool_memqcache.c
index acb7a74..f6d6ef7 100644
--- a/pool_memqcache.c
+++ b/pool_memqcache.c
@@ -1567,9 +1567,13 @@ static void pool_reset_memqcache_buffer(void)
 	{
 		POOL_TEMP_QUERY_CACHE *cache;
 
+		pool_debug("pool_reset_memqcache_buffer: discard: %p", session_context->query_cache_array);
+
 		pool_discard_query_cache_array(session_context->query_cache_array);
 		session_context->query_cache_array = pool_create_query_cache_array();
 
+		pool_debug("pool_reset_memqcache_buffer: create: %p", session_context->query_cache_array);
+
 		/*
 		 * if the query context is still under use, we cannot discard
 		 * temporary cache.
@@ -2579,8 +2583,11 @@ void pool_discard_query_cache_array(POOL_QUERY_CACHE_ARRAY *cache_array)
 	if (!cache_array)
 		return;
 
+	pool_debug("pool_discard_query_cache_array: num_caches: %d", cache_array->num_caches);
+
 	for (i=0;i<cache_array->num_caches;i++)
 	{
+		pool_debug("pool_discard_query_cache_array: i: %d cache: %p", i, cache_array->caches[i]);
 		pool_discard_temp_query_cache(cache_array->caches[i]);
 	}
 	free(cache_array);
@@ -2597,6 +2604,8 @@ static POOL_QUERY_CACHE_ARRAY * pool_add_query_cache_array(POOL_QUERY_CACHE_ARRA
 	if (!cache_array)
 		return cp;
 
+	pool_debug("pool_add_query_cache_array: num_caches: %d cache: %p", cache_array->num_caches, cache);
+
 	if (cache_array->num_caches >= 	cache_array->array_size)
 	{
 		cache_array->array_size += POOL_QUERY_CACHE_ARRAY_ALLOCATE_NUM;
@@ -2712,7 +2721,7 @@ static void pool_add_temp_query_cache(POOL_TEMP_QUERY_CACHE *temp_cache, char ki
 
 	if ((buflen+data_len+sizeof(int)+1) > pool_config->memqcache_maxcache)
 	{
-		pool_log("pool_add_temp_query_cache: data size exceeds memqcache_maxcache. current:%zd requested:%zd memq_maxcache:%d",
+		pool_debug("pool_add_temp_query_cache: data size exceeds memqcache_maxcache. current:%zd requested:%zd memq_maxcache:%d",
 				 buflen, data_len+sizeof(int)+1, pool_config->memqcache_maxcache);
 		temp_cache->is_exceeded = true;
 		return;
@@ -3048,6 +3057,16 @@ void pool_handle_query_cache(POOL_CONNECTION_POOL *backend, char *query, Node *n
 			{
 				session_context->query_cache_array = 
 					pool_add_query_cache_array(session_context->query_cache_array, cache);
+				/*
+				 * Reset temp_cache pointer in the current query
+				 * context so that we don't add the same temp cache to
+				 * the cache array. This is necessary such that case
+				 * when next query is just a "bind message", without
+				 * "parse message". In the case the query context is
+				 * reused and same cache pointer will be added to the
+				 * query_cache_array which we do not want.
+				 */
+				session_context->query_context->temp_cache = NULL;
 			}
 
 			/* Count up temporary SELECT stats */
pool_memqcache.c.patch (2,777 bytes)

Issue History

Date Modified Username Field Change
2013-08-05 12:35 harukat New Issue
2013-08-05 15:27 t-ishii Assigned To => t-ishii
2013-08-05 15:27 t-ishii Status new => assigned
2013-08-05 16:46 t-ishii Note Added: 0000310
2013-08-05 16:47 t-ishii File Added: pool_memqcache.c.patch
2013-08-05 16:47 t-ishii Status assigned => resolved
2013-08-05 22:01 t-ishii Changeset attached => pgpool2 master d11ef6ec
2013-08-05 22:01 t-ishii Changeset attached => pgpool2 master d6592ea7