View Issue Details

IDProjectCategoryView StatusLast Update
0000058Pgpool-IIBugpublic2013-06-12 20:01
ReporterwmsAssigned Tot-ishii 
PrioritynormalSeveritymajorReproducibilityalways
Status resolvedResolutionopen 
Platformx86_64OSOracle LinuxOS Version6.3
Product Version 
Target VersionFixed in Version 
Summary0000058: query cache invalidation does not fire for multiple DML in transaction
DescriptionI have the memory cache turned on with auto invalidation. It looks like I'm seeing a bug along the lines of:

SELECT x.* FROM x;
# returns data from backend, stores in cache

BEGIN
INSERT INTO x (a, b, c) VALUES (1,2,3);
DELETE FROM y WHERE z = 0;
COMMIT

SELECT x.* FROM x;
# returns cached data


I would have expected the INSERT in the transaction to invalidate the query cache. Note that the DELETE is for another table.

Additional Informationpgpool-II 3.2.3 and 3.2.4 with PostgreSQL 9.2
TagsNo tags attached.

Activities

wms

2013-05-08 08:53

reporter   ~0000268

I was able to work around it by performing the DELETE after the COMMIT, which is not ideal for my application, but it should be good enough for now.

t-ishii

2013-05-11 12:30

developer   ~0000269

Did not reproduce here.

CREATE TABLE t1(i INTEGER);
CREATE TABLE t2(i INTEGER);
SELECT * FROM t1;
BEGIN;
INSERT INTO t1(i) VALUES(1);
DELETE FROM t2 WHERE i = 0;
COMMIT;

SELECT * FROM t1;

The last SELECT correctly returns i = 1;

wms

2013-05-14 03:13

reporter  

pgpool_bug_58_logs.txt (115,539 bytes)
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT  "tB".* FROM "tB" WHERE "tB"."id" = 2231 ORDER BY tB.created_at DESC LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_has_insertinto_or_locking_clause: returns 0
May 10 08:10:29 server pgpool[16693]: pool_has_non_immutable_function_call: 0
May 10 08:10:29 server pgpool[16693]: temp_table_walker: relname: tB
May 10 08:10:29 server pgpool[16693]: system_catalog_walker: relname: tB
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tB
May 10 08:10:29 server pgpool[16693]: view_walker: relname: tB
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tB
May 10 08:10:29 server pgpool[16693]: unlogged_table_walker: relname: tB
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT  "tB".* FROM "tB" WHERE "tB"."id" = 2231 ORDER BY tB.created_at DESC LIMIT 1
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: T from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend T NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: T
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:1 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:5 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:311, total:316 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: D from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend D NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: D
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:317 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:321 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:202, total:523 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:524 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:528 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:9, total:537 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tB
May 10 08:10:29 server pgpool[16693]: select_table_walker: ctx->table_names[0] = tB
May 10 08:10:29 server pgpool[16693]: num_oids: 1 oid: 18047
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:4 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT  "tF".* FROM "tF" WHERE "tF"."property" = 'pcdt_id' ORDER BY property LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_has_insertinto_or_locking_clause: returns 0
May 10 08:10:29 server pgpool[16693]: pool_has_non_immutable_function_call: 0
May 10 08:10:29 server pgpool[16693]: temp_table_walker: relname: tF
May 10 08:10:29 server pgpool[16693]: system_catalog_walker: relname: tF
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tF
May 10 08:10:29 server pgpool[16693]: view_walker: relname: tF
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tF
May 10 08:10:29 server pgpool[16693]: unlogged_table_walker: relname: tF
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT  "tF".* FROM "tF" WHERE "tF"."property" = 'pcdt_id' ORDER BY property LIMIT 1
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: T from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend T NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: T
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:1 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:5 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:163, total:168 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: D from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend D NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: D
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:169 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:173 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:109, total:282 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:283 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:287 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:9, total:296 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tF
May 10 08:10:29 server pgpool[16693]: select_table_walker: ctx->table_names[0] = tF
May 10 08:10:29 server pgpool[16693]: num_oids: 1 oid: 17892
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:4 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT "tA".* FROM "tA" WHERE ("tA".b_id = 2231) ORDER BY tA.created_at DESC
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_has_insertinto_or_locking_clause: returns 0
May 10 08:10:29 server pgpool[16693]: pool_has_non_immutable_function_call: 0
May 10 08:10:29 server pgpool[16693]: temp_table_walker: relname: tA
May 10 08:10:29 server pgpool[16693]: system_catalog_walker: relname: tA
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tA
May 10 08:10:29 server pgpool[16693]: view_walker: relname: tA
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tA
May 10 08:10:29 server pgpool[16693]: unlogged_table_walker: relname: tA
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT "tA".* FROM "tA" WHERE ("tA".b_id = 2231) ORDER BY tA.created_at DESC
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: T from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend T NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: T
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:1 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:5 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:301, total:306 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: D from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend D NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: D
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:307 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:311 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:125, total:436 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:437 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:441 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:9, total:450 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tA
May 10 08:10:29 server pgpool[16693]: select_table_walker: ctx->table_names[0] = tA
May 10 08:10:29 server pgpool[16693]: num_oids: 1 oid: 17829
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:4 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: UPDATE "tB" SET "state" = 2, "updated_at" = '2013-05-10 08:11:00.337931', "lock_version" = 3 WHERE ("tB"."id" = 2231 AND "tB"."lock_version" = 2)
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_extract_table_oids: table:"tB" oid:18047
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: UPDATE "tB" SET "state" = 2, "updated_at" = '2013-05-10 08:11:00.337931', "lock_version" = 3 WHERE ("tB"."id" = 2231 AND "tB"."lock_version" = 2)
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: pool_set_writing_transaction: done
May 10 08:10:29 server pgpool[16693]: pool_check_and_discard_cache_buffer: discard cache for SELECT  "tB".* FROM "tB" WHERE "tB"."id" = 2231 ORDER BY tB.created_at DESC LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_check_and_discard_cache_buffer: discard cache for SELECT "tA".* FROM "tA" WHERE ("tA".b_id = 2231) ORDER BY tA.created_at DESC
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: UPDATE "tB" SET "decided_at" = '2013-05-10 08:11:00.340418', "updated_at" = '2013-05-10 08:11:00.340558', "lock_version" = 4 WHERE ("tB"."id" = 2231 AND "tB"."lock_version" = 3)
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_extract_table_oids: table:"tB" oid:18047
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: UPDATE "tB" SET "decided_at" = '2013-05-10 08:11:00.340418', "updated_at" = '2013-05-10 08:11:00.340558', "lock_version" = 4 WHERE ("tB"."id" = 2231 AND "tB"."lock_version" = 3)
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: pool_set_writing_transaction: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: UPDATE "tB" SET "updated_at" = '2013-05-10 08:11:00.342511', "lock_version" = 5 WHERE ("tB"."id" = 2231 AND "tB"."lock_version" = 4)
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_extract_table_oids: table:"tB" oid:18047
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: UPDATE "tB" SET "updated_at" = '2013-05-10 08:11:00.342511', "lock_version" = 5 WHERE ("tB"."id" = 2231 AND "tB"."lock_version" = 4)
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: pool_set_writing_transaction: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT  "tC".* FROM "tC" WHERE "tC"."id" = 2188 ORDER BY tC.number DESC LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_has_insertinto_or_locking_clause: returns 0
May 10 08:10:29 server pgpool[16693]: pool_has_non_immutable_function_call: 0
May 10 08:10:29 server pgpool[16693]: temp_table_walker: relname: tC
May 10 08:10:29 server pgpool[16693]: system_catalog_walker: relname: tC
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tC
May 10 08:10:29 server pgpool[16693]: view_walker: relname: tC
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tC
May 10 08:10:29 server pgpool[16693]: unlogged_table_walker: relname: tC
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT  "tC".* FROM "tC" WHERE "tC"."id" = 2188 ORDER BY tC.number DESC LIMIT 1
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: T from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend T NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: T
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:1 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:5 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:359, total:364 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: D from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend D NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: D
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:365 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:369 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:125, total:494 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:495 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:499 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:9, total:508 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tC
May 10 08:10:29 server pgpool[16693]: select_table_walker: ctx->table_names[0] = tC
May 10 08:10:29 server pgpool[16693]: num_oids: 1 oid: 18101
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:4 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT  "tH".* FROM "tH" WHERE "tH"."id" = 1583 ORDER BY tH.name, tH.version LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_has_insertinto_or_locking_clause: returns 0
May 10 08:10:29 server pgpool[16693]: pool_has_non_immutable_function_call: 0
May 10 08:10:29 server pgpool[16693]: temp_table_walker: relname: tH
May 10 08:10:29 server pgpool[16693]: system_catalog_walker: relname: tH
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tH
May 10 08:10:29 server pgpool[16693]: view_walker: relname: tH
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tH
May 10 08:10:29 server pgpool[16693]: unlogged_table_walker: relname: tH
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT  "tH".* FROM "tH" WHERE "tH"."id" = 1583 ORDER BY tH.name, tH.version LIMIT 1
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: T from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend T NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: T
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:1 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:5 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:227, total:232 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: D from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend D NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: D
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:233 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:237 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:113, total:350 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:351 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:355 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:9, total:364 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tH
May 10 08:10:29 server pgpool[16693]: select_table_walker: ctx->table_names[0] = tH
May 10 08:10:29 server pgpool[16693]: num_oids: 1 oid: 17877
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:4 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT  "tI".* FROM "tI" WHERE "tI"."name" IS NULL ORDER BY tI.name LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_has_insertinto_or_locking_clause: returns 0
May 10 08:10:29 server pgpool[16693]: pool_has_non_immutable_function_call: 0
May 10 08:10:29 server pgpool[16693]: temp_table_walker: relname: tI
May 10 08:10:29 server pgpool[16693]: system_catalog_walker: relname: tI
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tI
May 10 08:10:29 server pgpool[16693]: view_walker: relname: tI
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tI
May 10 08:10:29 server pgpool[16693]: unlogged_table_walker: relname: tI
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT  "tI".* FROM "tI" WHERE "tI"."name" IS NULL ORDER BY tI.name LIMIT 1
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: T from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend T NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: T
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:1 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:5 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:397, total:402 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:403 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:407 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:9, total:416 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tI
May 10 08:10:29 server pgpool[16693]: select_table_walker: ctx->table_names[0] = tI
May 10 08:10:29 server pgpool[16693]: num_oids: 1 oid: 18257
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:4 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT  * FROM "tD" INNER JOIN "tH_tD" ON "tD".id = "tH_tD".d_id WHERE ("tH_tD".cmp = 1583 ) ORDER BY tD.name LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_has_insertinto_or_locking_clause: returns 0
May 10 08:10:29 server pgpool[16693]: pool_has_non_immutable_function_call: 0
May 10 08:10:29 server pgpool[16693]: temp_table_walker: relname: tD
May 10 08:10:29 server pgpool[16693]: temp_table_walker: relname: tH_tD
May 10 08:10:29 server pgpool[16693]: system_catalog_walker: relname: tD
May 10 08:10:29 server pgpool[16693]: system_catalog_walker: relname: tH_tD
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tD
May 10 08:10:29 server pgpool[16693]: view_walker: relname: tD
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tH_tD
May 10 08:10:29 server pgpool[16693]: view_walker: relname: tH_tD
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tD
May 10 08:10:29 server pgpool[16693]: unlogged_table_walker: relname: tD
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tH_tD
May 10 08:10:29 server pgpool[16693]: unlogged_table_walker: relname: tH_tD
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT  * FROM "tD" INNER JOIN "tH_tD" ON "tD".id = "tH_tD".d_id WHERE ("tH_tD".cmp = 1583 ) ORDER BY tD.name LIMIT 1
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: T from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend T NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: T
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:1 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:5 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:225, total:230 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:231 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:235 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:9, total:244 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tD
May 10 08:10:29 server pgpool[16693]: select_table_walker: ctx->table_names[0] = tD
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tH_tD
May 10 08:10:29 server pgpool[16693]: select_table_walker: ctx->table_names[1] = tH_tD
May 10 08:10:29 server pgpool[16693]: num_oids: 2 oid: 18221
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:8, total:8 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: UPDATE "tB" SET "quotas_snapshot" = '{}', "updated_at" = '2013-05-10 08:11:00.354017', "lock_version" = 6 WHERE ("tB"."id" = 2231 AND "tB"."lock_version" = 5)
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_extract_table_oids: table:"tB" oid:18047
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: UPDATE "tB" SET "quotas_snapshot" = '{}', "updated_at" = '2013-05-10 08:11:00.354017', "lock_version" = 6 WHERE ("tB"."id" = 2231 AND "tB"."lock_version" = 5)
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: pool_set_writing_transaction: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT  "tG".* FROM "tG" WHERE "tG"."id" = 3 ORDER BY tG.id LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_has_insertinto_or_locking_clause: returns 0
May 10 08:10:29 server pgpool[16693]: pool_has_non_immutable_function_call: 0
May 10 08:10:29 server pgpool[16693]: temp_table_walker: relname: tG
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE c.relname = 'tG' AND c.relnamespace = n.oid AND n.nspname ~ '^pg_temp_'
May 10 08:10:29 server pgpool[16693]: do_query: extended:0 query:SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE c.relname = 'tG' AND c.relnamespace = n.oid AND n.nspname ~ '^pg_temp_'
May 10 08:10:29 server pgpool[16693]: do_query: kind: T
May 10 08:10:29 server pgpool[16693]: do_query: row description received
May 10 08:10:29 server pgpool[16693]: num_fileds: 1
May 10 08:10:29 server pgpool[16693]: do_query: kind: D
May 10 08:10:29 server pgpool[16693]: do_query: data row received
May 10 08:10:29 server pgpool[16693]: do_query: kind: C
May 10 08:10:29 server pgpool[16693]: do_query: Command complete received
May 10 08:10:29 server pgpool[16693]: do_query: kind: Z
May 10 08:10:29 server pgpool[16693]: do_query: Ready for query
May 10 08:10:29 server pgpool[16693]: system_catalog_walker: relname: tG
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE c.relname = 'tG' AND c.relnamespace = n.oid AND n.nspname = 'pg_catalog'
May 10 08:10:29 server pgpool[16693]: do_query: extended:0 query:SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE c.relname = 'tG' AND c.relnamespace = n.oid AND n.nspname = 'pg_catalog'
May 10 08:10:29 server pgpool[16693]: do_query: kind: T
May 10 08:10:29 server pgpool[16693]: do_query: row description received
May 10 08:10:29 server pgpool[16693]: num_fileds: 1
May 10 08:10:29 server pgpool[16693]: do_query: kind: D
May 10 08:10:29 server pgpool[16693]: do_query: data row received
May 10 08:10:29 server pgpool[16693]: do_query: kind: C
May 10 08:10:29 server pgpool[16693]: do_query: Command complete received
May 10 08:10:29 server pgpool[16693]: do_query: kind: Z
May 10 08:10:29 server pgpool[16693]: do_query: Ready for query
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tG
May 10 08:10:29 server pgpool[16693]: view_walker: relname: tG
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.relname = 'tG' AND c.relkind = 'v'
May 10 08:10:29 server pgpool[16693]: do_query: extended:0 query:SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.relname = 'tG' AND c.relkind = 'v'
May 10 08:10:29 server pgpool[16693]: do_query: kind: T
May 10 08:10:29 server pgpool[16693]: do_query: row description received
May 10 08:10:29 server pgpool[16693]: num_fileds: 1
May 10 08:10:29 server pgpool[16693]: do_query: kind: D
May 10 08:10:29 server pgpool[16693]: do_query: data row received
May 10 08:10:29 server pgpool[16693]: do_query: kind: C
May 10 08:10:29 server pgpool[16693]: do_query: Command complete received
May 10 08:10:29 server pgpool[16693]: do_query: kind: Z
May 10 08:10:29 server pgpool[16693]: do_query: Ready for query
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tG
May 10 08:10:29 server pgpool[16693]: unlogged_table_walker: relname: tG
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.relname = 'tG' AND c.relpersistence = 'u'
May 10 08:10:29 server pgpool[16693]: do_query: extended:0 query:SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.relname = 'tG' AND c.relpersistence = 'u'
May 10 08:10:29 server pgpool[16693]: do_query: kind: T
May 10 08:10:29 server pgpool[16693]: do_query: row description received
May 10 08:10:29 server pgpool[16693]: num_fileds: 1
May 10 08:10:29 server pgpool[16693]: do_query: kind: D
May 10 08:10:29 server pgpool[16693]: do_query: data row received
May 10 08:10:29 server pgpool[16693]: do_query: kind: C
May 10 08:10:29 server pgpool[16693]: do_query: Command complete received
May 10 08:10:29 server pgpool[16693]: do_query: kind: Z
May 10 08:10:29 server pgpool[16693]: do_query: Ready for query
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT  "tG".* FROM "tG" WHERE "tG"."id" = 3 ORDER BY tG.id LIMIT 1
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: T from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend T NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: T
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:1 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:5 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:135, total:140 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: D from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend D NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: D
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:141 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:145 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:82, total:227 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:228 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:232 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:9, total:241 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tG
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT oid FROM pg_class WHERE relname = 'tG'
May 10 08:10:29 server pgpool[16693]: do_query: extended:0 query:SELECT oid FROM pg_class WHERE relname = 'tG'
May 10 08:10:29 server pgpool[16693]: do_query: kind: T
May 10 08:10:29 server pgpool[16693]: do_query: row description received
May 10 08:10:29 server pgpool[16693]: num_fileds: 1
May 10 08:10:29 server pgpool[16693]: do_query: kind: D
May 10 08:10:29 server pgpool[16693]: do_query: data row received
May 10 08:10:29 server pgpool[16693]: do_query: kind: C
May 10 08:10:29 server pgpool[16693]: do_query: Command complete received
May 10 08:10:29 server pgpool[16693]: do_query: kind: Z
May 10 08:10:29 server pgpool[16693]: do_query: Ready for query
May 10 08:10:29 server pgpool[16693]: select_table_walker: ctx->table_names[0] = tG
May 10 08:10:29 server pgpool[16693]: num_oids: 1 oid: 17820
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:4 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT  "tE".* FROM "tE" WHERE "tE"."id" = 1 ORDER BY tE.rn LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_has_insertinto_or_locking_clause: returns 0
May 10 08:10:29 server pgpool[16693]: pool_has_non_immutable_function_call: 0
May 10 08:10:29 server pgpool[16693]: temp_table_walker: relname: tE
May 10 08:10:29 server pgpool[16693]: system_catalog_walker: relname: tE
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tE
May 10 08:10:29 server pgpool[16693]: view_walker: relname: tE
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tE
May 10 08:10:29 server pgpool[16693]: unlogged_table_walker: relname: tE
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT  "tE".* FROM "tE" WHERE "tE"."id" = 1 ORDER BY tE.rn LIMIT 1
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: T from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend T NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: T
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:1 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:5 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:283, total:288 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: D from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend D NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: D
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:289 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:293 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:207, total:500 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:501 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:505 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:9, total:514 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tE
May 10 08:10:29 server pgpool[16693]: select_table_walker: ctx->table_names[0] = tE
May 10 08:10:29 server pgpool[16693]: num_oids: 1 oid: 18270
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:4 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT  "tE".* FROM "tE" WHERE "tE"."id" = 24 ORDER BY tE.rn LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_has_insertinto_or_locking_clause: returns 0
May 10 08:10:29 server pgpool[16693]: pool_has_non_immutable_function_call: 0
May 10 08:10:29 server pgpool[16693]: temp_table_walker: relname: tE
May 10 08:10:29 server pgpool[16693]: system_catalog_walker: relname: tE
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tE
May 10 08:10:29 server pgpool[16693]: view_walker: relname: tE
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tE
May 10 08:10:29 server pgpool[16693]: unlogged_table_walker: relname: tE
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT  "tE".* FROM "tE" WHERE "tE"."id" = 24 ORDER BY tE.rn LIMIT 1
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: T from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend T NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: T
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:1 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:5 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:283, total:288 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: D from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend D NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: D
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:289 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:293 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:179, total:472 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:473 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:477 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:9, total:486 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tE
May 10 08:10:29 server pgpool[16693]: select_table_walker: ctx->table_names[0] = tE
May 10 08:10:29 server pgpool[16693]: num_oids: 1 oid: 18270
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:4 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: INSERT INTO "tP" ("rrr", "data", "complete", "created_at", "updated_at", "lock_version") VALUES (2188, '{}', 'f', '2013-05-10 08:11:00.365758', '2013-05-10 08:11:00.365758', 0) RETURNING "id"
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_extract_table_oids: table:"tP" oid:18091
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: INSERT INTO "tP" ("rrr", "data", "complete", "created_at", "updated_at", "lock_version") VALUES (2188, '{}', 'f', '2013-05-10 08:11:00.365758', '2013-05-10 08:11:00.365758', 0) RETURNING "id"
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: T from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend T NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: T
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: D from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend D NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: D
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: pool_set_writing_transaction: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT  "tI".* FROM "tI" WHERE "tI"."name" IS NULL ORDER BY tI.name LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_has_insertinto_or_locking_clause: returns 0
May 10 08:10:29 server pgpool[16693]: pool_has_non_immutable_function_call: 0
May 10 08:10:29 server pgpool[16693]: temp_table_walker: relname: tI
May 10 08:10:29 server pgpool[16693]: system_catalog_walker: relname: tI
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tI
May 10 08:10:29 server pgpool[16693]: view_walker: relname: tI
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tI
May 10 08:10:29 server pgpool[16693]: unlogged_table_walker: relname: tI
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT  "tI".* FROM "tI" WHERE "tI"."name" IS NULL ORDER BY tI.name LIMIT 1
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: T from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend T NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: T
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:1 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:5 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:397, total:402 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:403 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:407 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:9, total:416 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tI
May 10 08:10:29 server pgpool[16693]: select_table_walker: ctx->table_names[0] = tI
May 10 08:10:29 server pgpool[16693]: num_oids: 1 oid: 18257
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:4 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT "tJ".* FROM "tJ" WHERE (tJ.j_id=0 AND tJ.ddd_at<'2013-05-10 08:11:00.370767') ORDER BY ddd_at
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_has_insertinto_or_locking_clause: returns 0
May 10 08:10:29 server pgpool[16693]: pool_has_non_immutable_function_call: 0
May 10 08:10:29 server pgpool[16693]: temp_table_walker: relname: tJ
May 10 08:10:29 server pgpool[16693]: system_catalog_walker: relname: tJ
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tJ
May 10 08:10:29 server pgpool[16693]: view_walker: relname: tJ
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tJ
May 10 08:10:29 server pgpool[16693]: unlogged_table_walker: relname: tJ
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT "tJ".* FROM "tJ" WHERE (tJ.j_id=0 AND tJ.ddd_at<'2013-05-10 08:11:00.370767') ORDER BY ddd_at
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: T from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend T NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: T
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:1 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:5 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:192, total:197 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:198 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:202 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:9, total:211 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tJ
May 10 08:10:29 server pgpool[16693]: select_table_walker: ctx->table_names[0] = tJ
May 10 08:10:29 server pgpool[16693]: num_oids: 1 oid: 17901
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:4 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: COMMIT
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_extract_table_oids: other than INSERT/UPDATE/DELETE/TRUNCATE/DROP TABLE/ALTER TABLE statement
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: COMMIT
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: pool_unset_writing_transaction: done
May 10 08:10:29 server pgpool[16693]: pool_unset_failed_transaction: done
May 10 08:10:29 server pgpool[16693]: pool_unset_transaction_isolation: done
May 10 08:10:29 server pgpool[16693]: pool_invalidate_query_cache: dboid 17756
May 10 08:10:29 server pgpool[16693]: pool_invalidate_query_cache: failed to open /var/log/pgpool/oiddir/17756/17829. reason:No such file or directory
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: Query=SELECT  "tF".* FROM "tF" WHERE "tF"."property" = 'pcdt_id' ORDER BY property LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT  "tF".* FROM "tF" WHERE "tF"."property" = 'pcdt_id' ORDER BY property LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT  "tF".* FROM "tF" WHERE "tF"."property" = 'pcdt_id' ORDER BY property LIMIT 1dbname_production' -> `34ee0f45034b597a5bfb773341d53944'
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: search key ==34ee0f45034b597a5bfb773341d53944==
May 10 08:10:29 server pgpool[16693]: pool_commit_cache : memqcache_expire = 0
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: the item already exists
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: Query=SELECT  "tC".* FROM "tC" WHERE "tC"."id" = 2188 ORDER BY tC.number DESC LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT  "tC".* FROM "tC" WHERE "tC"."id" = 2188 ORDER BY tC.number DESC LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT  "tC".* FROM "tC" WHERE "tC"."id" = 2188 ORDER BY tC.number DESC LIMIT 1dbname_production' -> `9c933e9787e9fde189a88cd7393ffa9f'
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: search key ==9c933e9787e9fde189a88cd7393ffa9f==
May 10 08:10:29 server pgpool[16693]: pool_commit_cache : memqcache_expire = 0
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: the item already exists
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: Query=SELECT  "tH".* FROM "tH" WHERE "tH"."id" = 1583 ORDER BY tH.name, tH.version LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT  "tH".* FROM "tH" WHERE "tH"."id" = 1583 ORDER BY tH.name, tH.version LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT  "tH".* FROM "tH" WHERE "tH"."id" = 1583 ORDER BY tH.name, tH.version LIMIT 1dbname_production' -> `893e91d0572480e6c31d06b5c37ba2c2'
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: search key ==893e91d0572480e6c31d06b5c37ba2c2==
May 10 08:10:29 server pgpool[16693]: pool_commit_cache : memqcache_expire = 0
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: the item already exists
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: Query=SELECT  "tI".* FROM "tI" WHERE "tI"."name" IS NULL ORDER BY tI.name LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT  "tI".* FROM "tI" WHERE "tI"."name" IS NULL ORDER BY tI.name LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT  "tI".* FROM "tI" WHERE "tI"."name" IS NULL ORDER BY tI.name LIMIT 1dbname_production' -> `cccb1b418b8d2fe19ff831de38e51ab0'
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: search key ==cccb1b418b8d2fe19ff831de38e51ab0==
May 10 08:10:29 server pgpool[16693]: pool_commit_cache : memqcache_expire = 0
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: the item already exists
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: Query=SELECT  * FROM "tD" INNER JOIN "tH_tD" ON "tD".id = "tH_tD".d_id WHERE ("tH_tD".cmp = 1583 ) ORDER BY tD.name LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT  * FROM "tD" INNER JOIN "tH_tD" ON "tD".id = "tH_tD".d_id WHERE ("tH_tD".cmp = 1583 ) ORDER BY tD.name LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT  * FROM "tD" INNER JOIN "tH_tD" ON "tD".id = "tH_tD".d_id WHERE ("tH_tD".cmp = 1583 ) ORDER BY tD.name LIMIT 1dbname_production' -> `2a1425adbd04e6852986849489558aa4'
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: search key ==2a1425adbd04e6852986849489558aa4==
May 10 08:10:29 server pgpool[16693]: pool_commit_cache : memqcache_expire = 0
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: the item already exists
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: Query=SELECT  "tG".* FROM "tG" WHERE "tG"."id" = 3 ORDER BY tG.id LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT  "tG".* FROM "tG" WHERE "tG"."id" = 3 ORDER BY tG.id LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT  "tG".* FROM "tG" WHERE "tG"."id" = 3 ORDER BY tG.id LIMIT 1dbname_production' -> `30717a0f389c2562441d2d3c3ff07ce7'
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: search key ==30717a0f389c2562441d2d3c3ff07ce7==
May 10 08:10:29 server pgpool[16693]: pool_commit_cache : memqcache_expire = 0
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: the item already exists
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: Query=SELECT  "tE".* FROM "tE" WHERE "tE"."id" = 1 ORDER BY tE.rn LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT  "tE".* FROM "tE" WHERE "tE"."id" = 1 ORDER BY tE.rn LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT  "tE".* FROM "tE" WHERE "tE"."id" = 1 ORDER BY tE.rn LIMIT 1dbname_production' -> `723197d06ed98fc19c033dc3ce590dca'
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: search key ==723197d06ed98fc19c033dc3ce590dca==
May 10 08:10:29 server pgpool[16693]: pool_commit_cache : memqcache_expire = 0
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: the item already exists
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: Query=SELECT  "tE".* FROM "tE" WHERE "tE"."id" = 24 ORDER BY tE.rn LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT  "tE".* FROM "tE" WHERE "tE"."id" = 24 ORDER BY tE.rn LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT  "tE".* FROM "tE" WHERE "tE"."id" = 24 ORDER BY tE.rn LIMIT 1dbname_production' -> `a103b88fd5fd0dcb5fe95190119445e8'
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: search key ==a103b88fd5fd0dcb5fe95190119445e8==
May 10 08:10:29 server pgpool[16693]: pool_commit_cache : memqcache_expire = 0
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: the item already exists
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: Query=SELECT  "tI".* FROM "tI" WHERE "tI"."name" IS NULL ORDER BY tI.name LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT  "tI".* FROM "tI" WHERE "tI"."name" IS NULL ORDER BY tI.name LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT  "tI".* FROM "tI" WHERE "tI"."name" IS NULL ORDER BY tI.name LIMIT 1dbname_production' -> `cccb1b418b8d2fe19ff831de38e51ab0'
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: search key ==cccb1b418b8d2fe19ff831de38e51ab0==
May 10 08:10:29 server pgpool[16693]: pool_commit_cache : memqcache_expire = 0
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: the item already exists
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: Query=SELECT "tJ".* FROM "tJ" WHERE (tJ.j_id=0 AND tJ.ddd_at<'2013-05-10 08:11:00.370767') ORDER BY ddd_at
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT "tJ".* FROM "tJ" WHERE (tJ.j_id=0 AND tJ.ddd_at<'2013-05-10 08:11:00.370767') ORDER BY ddd_at
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT "tJ".* FROM "tJ" WHERE (tJ.j_id=0 AND tJ.ddd_at<'2013-05-10 08:11:00.370767') ORDER BY ddd_atdbname_production' -> `2b8a5eafd5cf82cd1c0df9a945ccd53d'
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: search key ==2b8a5eafd5cf82cd1c0df9a945ccd53d==
May 10 08:10:29 server pgpool[16693]: pool_commit_cache : memqcache_expire = 0
May 10 08:10:29 server pgpool[16693]: pool_add_item_shmem_cache: start creating contiguous space
May 10 08:10:29 server pgpool[16693]: pool_add_item_shmem_cache: new item inserted. blockid: 51 itemid:801
May 10 08:10:29 server pgpool[16693]: pool_add_item_shmem_cache: block: 51 item: 801
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: blockid: 51 itemid: 801
May 10 08:10:29 server pgpool[16693]: pool_add_table_oid_map: dboid 17756
May 10 08:10:29 server pgpool[16693]: pool_reset_memqcache_buffer: discard temp buffer of 0x1b55160 (COMMIT)
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: DELETE FROM "tK" WHERE "tK"."pt" = 'cd'
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_extract_table_oids: table:"tK" oid:19744
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: DELETE FROM "tK" WHERE "tK"."pt" = 'cd'
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:I
May 10 08:10:29 server pgpool[16693]: pool_invalidate_query_cache: dboid 17756
May 10 08:10:29 server pgpool[16693]: pool_invalidate_query_cache: failed to open /var/log/pgpool/oiddir/17756/19744. reason:No such file or directory
May 10 08:10:29 server pgpool[16693]: pool_reset_memqcache_buffer: discard temp buffer of 0x1b546d0 (DELETE FROM "tK" WHERE "tK"."pt" = 'cd')
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: DELETE FROM "tK" WHERE "tK"."pt" = 'nom'
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_extract_table_oids: table:"tK" oid:19744
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: DELETE FROM "tK" WHERE "tK"."pt" = 'nom'
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:I
May 10 08:10:29 server pgpool[16693]: pool_invalidate_query_cache: dboid 17756
May 10 08:10:29 server pgpool[16693]: pool_invalidate_query_cache: failed to open /var/log/pgpool/oiddir/17756/19744. reason:No such file or directory
May 10 08:10:29 server pgpool[16693]: pool_reset_memqcache_buffer: discard temp buffer of 0x1b546d0 (DELETE FROM "tK" WHERE "tK"."pt" = 'nom')
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: DELETE FROM "tK" WHERE "tK"."pt" = 'cd'
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_extract_table_oids: table:"tK" oid:19744
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: DELETE FROM "tK" WHERE "tK"."pt" = 'cd'
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:I
May 10 08:10:29 server pgpool[16693]: pool_invalidate_query_cache: dboid 17756
May 10 08:10:29 server pgpool[16693]: pool_invalidate_query_cache: failed to open /var/log/pgpool/oiddir/17756/19744. reason:No such file or directory
May 10 08:10:29 server pgpool[16693]: pool_reset_memqcache_buffer: discard temp buffer of 0x1b546d0 (DELETE FROM "tK" WHERE "tK"."pt" = 'cd')
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: DELETE FROM "tK" WHERE "tK"."pt" = 'ro'
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_extract_table_oids: table:"tK" oid:19744
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: DELETE FROM "tK" WHERE "tK"."pt" = 'ro'
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:I
May 10 08:10:29 server pgpool[16693]: pool_invalidate_query_cache: dboid 17756
May 10 08:10:29 server pgpool[16693]: pool_invalidate_query_cache: failed to open /var/log/pgpool/oiddir/17756/19744. reason:No such file or directory
May 10 08:10:29 server pgpool[16693]: pool_reset_memqcache_buffer: discard temp buffer of 0x1b546d0 (DELETE FROM "tK" WHERE "tK"."pt" = 'ro')
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT  "tG".* FROM "tG" WHERE "tG"."id" = 3 ORDER BY tG.id LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT  "tG".* FROM "tG" WHERE "tG"."id" = 3 ORDER BY tG.id LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT  "tG".* FROM "tG" WHERE "tG"."id" = 3 ORDER BY tG.id LIMIT 1dbname_production' -> `30717a0f389c2562441d2d3c3ff07ce7'
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: search key ==30717a0f389c2562441d2d3c3ff07ce7==
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: query=SELECT  "tG".* FROM "tG" WHERE "tG"."id" = 3 ORDER BY tG.id LIMIT 1 len:241
May 10 08:10:29 server pgpool[16693]: send_cached_messages: T len: 139
May 10 08:10:29 server pgpool[16693]: send_message: kind=T, len=139, data=0x1b53975
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 86
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=86, data=0x1b53a01
May 10 08:10:29 server pgpool[16693]: send_cached_messages: C len: 13
May 10 08:10:29 server pgpool[16693]: send_message: kind=C, len=13, data=0x1b53a58
May 10 08:10:29 server pgpool[16693]: send_message: kind=Z, len=5, data=0x7fff08494ccf
May 10 08:10:29 server pgpool[16693]: query result fetched from cache. statement: SELECT  "tG".* FROM "tG" WHERE "tG"."id" = 3 ORDER BY tG.id LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_fetch_from_memory_cache: a query result found in the query cache, SELECT  "tG".* FROM "tG" WHERE "tG"."id" = 3 ORDER BY tG.id LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_set_skip_reading_from_backends: done
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT  "tE".* FROM "tE" WHERE "tE"."ds" = 12345678 ORDER BY tE.rn LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT  "tE".* FROM "tE" WHERE "tE"."ds" = 12345678 ORDER BY tE.rn LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT  "tE".* FROM "tE" WHERE "tE"."ds" = 12345678 ORDER BY tE.rn LIMIT 1dbname_production' -> `0edc37f34f65f053bdc290d65f1c484d'
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: search key ==0edc37f34f65f053bdc290d65f1c484d==
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: query=SELECT  "tE".* FROM "tE" WHERE "tE"."ds" = 12345678 ORDER BY tE.rn LIMIT 1 len:514
May 10 08:10:29 server pgpool[16693]: send_cached_messages: T len: 287
May 10 08:10:29 server pgpool[16693]: send_message: kind=T, len=287, data=0x1b546d5
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 211
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=211, data=0x1b547f5
May 10 08:10:29 server pgpool[16693]: send_cached_messages: C len: 13
May 10 08:10:29 server pgpool[16693]: send_message: kind=C, len=13, data=0x1b548c9
May 10 08:10:29 server pgpool[16693]: send_message: kind=Z, len=5, data=0x7fff08494ccf
May 10 08:10:29 server pgpool[16693]: query result fetched from cache. statement: SELECT  "tE".* FROM "tE" WHERE "tE"."ds" = 12345678 ORDER BY tE.rn LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_fetch_from_memory_cache: a query result found in the query cache, SELECT  "tE".* FROM "tE" WHERE "tE"."ds" = 12345678 ORDER BY tE.rn LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_set_skip_reading_from_backends: done
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT * FROM "tL" INNER JOIN "tL_tE" ON "tL".id = "tL_tE".l_id WHERE ("tL_tE".e_id = 1 ) ORDER BY tL.name
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT * FROM "tL" INNER JOIN "tL_tE" ON "tL".id = "tL_tE".l_id WHERE ("tL_tE".e_id = 1 ) ORDER BY tL.name
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT * FROM "tL" INNER JOIN "tL_tE" ON "tL".id = "tL_tE".l_id WHERE ("tL_tE".e_id = 1 ) ORDER BY tL.namedbname_production' -> `5ce11fcc79989343b201657dcbd5326e'
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: search key ==5ce11fcc79989343b201657dcbd5326e==
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: query=SELECT * FROM "tL" INNER JOIN "tL_tE" ON "tL".id = "tL_tE".l_id WHERE ("tL_tE".e_id = 1 ) ORDER BY tL.name len:4347
May 10 08:10:29 server pgpool[16693]: send_cached_messages: T len: 252
May 10 08:10:29 server pgpool[16693]: send_message: kind=T, len=252, data=0x1b55655
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 128
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=128, data=0x1b55752
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 126
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=126, data=0x1b557d3
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 127
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=127, data=0x1b55852
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 125
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=125, data=0x1b558d2
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 126
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=126, data=0x1b55950
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 125
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=125, data=0x1b559cf
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 142
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=142, data=0x1b55a4d
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 123
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=123, data=0x1b55adc
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 121
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=121, data=0x1b55b58
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 122
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=122, data=0x1b55bd2
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 129
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=129, data=0x1b55c4d
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 126
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=126, data=0x1b55ccf
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 123
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=123, data=0x1b55d4e
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 127
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=127, data=0x1b55dca
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 117
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=117, data=0x1b55e4a
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 116
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=116, data=0x1b55ec0
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 121
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=121, data=0x1b55f35
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 125
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=125, data=0x1b55faf
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 120
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=120, data=0x1b5602d
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 126
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=126, data=0x1b560a6
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 136
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=136, data=0x1b56125
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 135
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=135, data=0x1b561ae
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 139
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=139, data=0x1b56236
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 126
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=126, data=0x1b562c2
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 128
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=128, data=0x1b56341
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 125
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=125, data=0x1b563c2
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 128
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=128, data=0x1b56440
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 122
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=122, data=0x1b564c1
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 126
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=126, data=0x1b5653c
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 128
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=128, data=0x1b565bb
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 131
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=131, data=0x1b5663c
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 128
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=128, data=0x1b566c0
May 10 08:10:29 server pgpool[16693]: send_cached_messages: C len: 14
May 10 08:10:29 server pgpool[16693]: send_message: kind=C, len=14, data=0x1b56741
May 10 08:10:29 server pgpool[16693]: send_message: kind=Z, len=5, data=0x7fff08494ccf
May 10 08:10:29 server pgpool[16693]: query result fetched from cache. statement: SELECT * FROM "tL" INNER JOIN "tL_tE" ON "tL".id = "tL_tE".l_id WHERE ("tL_tE".e_id = 1 ) ORDER BY tL.name
May 10 08:10:29 server pgpool[16693]: pool_fetch_from_memory_cache: a query result found in the query cache, SELECT * FROM "tL" INNER JOIN "tL_tE" ON "tL".id = "tL_tE".l_id WHERE ("tL_tE".e_id = 1 ) ORDER BY tL.name
May 10 08:10:29 server pgpool[16693]: pool_set_skip_reading_from_backends: done
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT "tO".* FROM "tO" WHERE (e_id = 1 OR l_id in (1158,1188,1177,1167,1227,1166,1175,1154,1160,1163,1179,1185,123,1183,124,126,1191,115,120,117,1230,1231,1229,1147,1139,1149,1162,1165,1228,1148,1168,1146))
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT "tO".* FROM "tO" WHERE (e_id = 1 OR l_id in (1158,1188,1177,1167,1227,1166,1175,1154,1160,1163,1179,1185,123,1183,124,126,1191,115,120,117,1230,1231,1229,1147,1139,1149,1162,1165,1228,1148,1168,1146))
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT "tO".* FROM "tO" WHERE (e_id = 1 OR l_id in (1158,1188,1177,1167,1227,1166,1175,1154,1160,1163,1179,1185,123,1183,124,126,1191,115,120,117,1230,1231,1229,1147,1139,1149,1162,1165,1228,1148,1168,1146))dbname_production' -> `6f948c09bde6e010b9ab04b805377728'
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: search key ==6f948c09bde6e010b9ab04b805377728==
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: query=SELECT "tO".* FROM "tO" WHERE (e_id = 1 OR l_id in (1158,1188,1177,1167,1227,1166,1175,1154,1160,1163,1179,1185,123,1183,124,126,1191,115,120,117,1230,1231,1229,1147,1139,1149,1162,1165,1228,1148,1168,1146)) len:868
May 10 08:10:29 server pgpool[16693]: send_cached_messages: T len: 351
May 10 08:10:29 server pgpool[16693]: send_message: kind=T, len=351, data=0x1b54f85
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 125
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=125, data=0x1b550e5
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 125
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=125, data=0x1b55163
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 123
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=123, data=0x1b551e1
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 125
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=125, data=0x1b5525d
May 10 08:10:29 server pgpool[16693]: send_cached_messages: C len: 13
May 10 08:10:29 server pgpool[16693]: send_message: kind=C, len=13, data=0x1b552db
May 10 08:10:29 server pgpool[16693]: send_message: kind=Z, len=5, data=0x7fff08494ccf
May 10 08:10:29 server pgpool[16693]: query result fetched from cache. statement: SELECT "tO".* FROM "tO" WHERE (e_id = 1 OR l_id in (1158,1188,1177,1167,1227,1166,1175,1154,1160,1163,1179,1185,123,1183,124,126,1191,115,120,117,1230,1231,1229,1147,1139,1149,1162,1165,1228,1148,1168,1146))
May 10 08:10:29 server pgpool[16693]: pool_fetch_from_memory_cache: a query result found in the query cache, SELECT "tO".* FROM "tO" WHERE (e_id = 1 OR l_id in (1158,1188,1177,1167,1227,1166,1175,1154,1160,1163,1179,1185,123,1183,124,126,1191,115,120,117,1230,1231,1229,1147,1139,1149,1162,1165,1228,1148,1168,1146))
May 10 08:10:29 server pgpool[16693]: pool_set_skip_reading_from_backends: done
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT "tN".* FROM "tN" INNER JOIN "tM" ON "tN".id = "tM".n_id WHERE (("tM".e_id = 1)) ORDER BY tN.name
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT "tN".* FROM "tN" INNER JOIN "tM" ON "tN".id = "tM".n_id WHERE (("tM".e_id = 1)) ORDER BY tN.name
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT "tN".* FROM "tN" INNER JOIN "tM" ON "tN".id = "tM".n_id WHERE (("tM".e_id = 1)) ORDER BY tN.namedbname_production' -> `b764ce653afd27596eaf36d7d7383e3f'
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: search key ==b764ce653afd27596eaf36d7d7383e3f==
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: query=SELECT "tN".* FROM "tN" INNER JOIN "tM" ON "tN".id = "tM".n_id WHERE (("tM".e_id = 1)) ORDER BY tN.name len:684
May 10 08:10:29 server pgpool[16693]: send_cached_messages: T len: 303
May 10 08:10:29 server pgpool[16693]: send_message: kind=T, len=303, data=0x1b546d5
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 134
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=134, data=0x1b54805
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 134
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=134, data=0x1b5488c
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 95
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=95, data=0x1b54913
May 10 08:10:29 server pgpool[16693]: send_cached_messages: C len: 13
May 10 08:10:29 server pgpool[16693]: send_message: kind=C, len=13, data=0x1b54973
May 10 08:10:29 server pgpool[16693]: send_message: kind=Z, len=5, data=0x7fff08494ccf
May 10 08:10:29 server pgpool[16693]: query result fetched from cache. statement: SELECT "tN".* FROM "tN" INNER JOIN "tM" ON "tN".id = "tM".n_id WHERE (("tM".e_id = 1)) ORDER BY tN.name
May 10 08:10:29 server pgpool[16693]: pool_fetch_from_memory_cache: a query result found in the query cache, SELECT "tN".* FROM "tN" INNER JOIN "tM" ON "tN".id = "tM".n_id WHERE (("tM".e_id = 1)) ORDER BY tN.name
May 10 08:10:29 server pgpool[16693]: pool_set_skip_reading_from_backends: done
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT  "tA".* FROM "tA" WHERE "tA"."id" = 953 ORDER BY tA.created_at DESC LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT  "tA".* FROM "tA" WHERE "tA"."id" = 953 ORDER BY tA.created_at DESC LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT  "tA".* FROM "tA" WHERE "tA"."id" = 953 ORDER BY tA.created_at DESC LIMIT 1dbname_production' -> `fc60a1f61a6c74d8fa3feaef4f9b6de4'
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: search key ==fc60a1f61a6c74d8fa3feaef4f9b6de4==
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: cache not found on shmem
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_has_insertinto_or_locking_clause: returns 0
May 10 08:10:29 server pgpool[16693]: pool_has_non_immutable_function_call: 0
May 10 08:10:29 server pgpool[16693]: temp_table_walker: relname: tA
May 10 08:10:29 server pgpool[16693]: system_catalog_walker: relname: tA
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tA
May 10 08:10:29 server pgpool[16693]: view_walker: relname: tA
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tA
May 10 08:10:29 server pgpool[16693]: unlogged_table_walker: relname: tA
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT  "tA".* FROM "tA" WHERE "tA"."id" = 953 ORDER BY tA.created_at DESC LIMIT 1
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: pool_unset_skip_reading_from_backends: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: T from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend T NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: T
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:1 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:5 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:301, total:306 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: D from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend D NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: D
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:307 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:311 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:125, total:436 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:437 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:441 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:9, total:450 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:I
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tA
May 10 08:10:29 server pgpool[16693]: select_table_walker: ctx->table_names[0] = tA
May 10 08:10:29 server pgpool[16693]: num_oids: 1 oid: 17829
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: Query=SELECT  "tA".* FROM "tA" WHERE "tA"."id" = 953 ORDER BY tA.created_at DESC LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT  "tA".* FROM "tA" WHERE "tA"."id" = 953 ORDER BY tA.created_at DESC LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT  "tA".* FROM "tA" WHERE "tA"."id" = 953 ORDER BY tA.created_at DESC LIMIT 1dbname_production' -> `fc60a1f61a6c74d8fa3feaef4f9b6de4'
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: search key ==fc60a1f61a6c74d8fa3feaef4f9b6de4==
May 10 08:10:29 server pgpool[16693]: pool_commit_cache : memqcache_expire = 0
May 10 08:10:29 server pgpool[16693]: pool_add_item_shmem_cache: start creating contiguous space
May 10 08:10:29 server pgpool[16693]: pool_add_item_shmem_cache: new item inserted. blockid: 51 itemid:802
May 10 08:10:29 server pgpool[16693]: pool_add_item_shmem_cache: block: 51 item: 802
May 10 08:10:29 server pgpool[16693]: pool_commit_cache: blockid: 51 itemid: 802
May 10 08:10:29 server pgpool[16693]: pool_add_table_oid_map: dboid 17756
May 10 08:10:29 server pgpool[16693]: pool_reset_memqcache_buffer: discard temp buffer of 0x1b546d0 (SELECT  "tA".* FROM "tA" WHERE "tA"."id" = 953 ORDER BY tA.created_at DESC LIMIT 1)
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: BEGIN
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_extract_table_oids: other than INSERT/UPDATE/DELETE/TRUNCATE/DROP TABLE/ALTER TABLE statement
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: BEGIN
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_unset_writing_transaction: done
May 10 08:10:29 server pgpool[16693]: pool_unset_failed_transaction: done
May 10 08:10:29 server pgpool[16693]: pool_unset_transaction_isolation: done
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: pool_unset_writing_transaction: done
May 10 08:10:29 server pgpool[16693]: pool_unset_failed_transaction: done
May 10 08:10:29 server pgpool[16693]: pool_unset_transaction_isolation: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT "tO".* FROM "tO" WHERE ("tO".permissible_id = 953 AND "tO".pt = 'cd')
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT "tO".* FROM "tO" WHERE ("tO".permissible_id = 953 AND "tO".pt = 'cd')
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT "tO".* FROM "tO" WHERE ("tO".permissible_id = 953 AND "tO".pt = 'cd')dbname_production' -> `2e14e4f554b3315750445ec320359832'
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: search key ==2e14e4f554b3315750445ec320359832==
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: cache not found on shmem
May 10 08:10:29 server pgpool[16693]: pool_set_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_has_insertinto_or_locking_clause: returns 0
May 10 08:10:29 server pgpool[16693]: pool_has_non_immutable_function_call: 0
May 10 08:10:29 server pgpool[16693]: temp_table_walker: relname: tO
May 10 08:10:29 server pgpool[16693]: system_catalog_walker: relname: tO
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tO
May 10 08:10:29 server pgpool[16693]: view_walker: relname: tO
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tO
May 10 08:10:29 server pgpool[16693]: unlogged_table_walker: relname: tO
May 10 08:10:29 server pgpool[16693]: DB node id: 0 backend pid: 19776 statement: SELECT "tO".* FROM "tO" WHERE ("tO".permissible_id = 953 AND "tO".pt = 'cd')
May 10 08:10:29 server pgpool[16693]: wait_for_query_response: waiting for backend 0 completing the query
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: T from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend T NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: T
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:1 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:5 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:347, total:352 bufsize:8192
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: C from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: C
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:1, total:353 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:357 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:9, total:366 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_set_command_success: done
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: kind: Z from 0 th backend
May 10 08:10:29 server pgpool[16693]: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 1
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: kind from backend: Z
May 10 08:10:29 server pgpool[16693]: pool_read_message_length: slot: 0 length: 5
May 10 08:10:29 server pgpool[16693]: ReadyForQuery: transaction state:T
May 10 08:10:29 server pgpool[16693]: make_table_name_from_rangevar: tablename:tO
May 10 08:10:29 server pgpool[16693]: select_table_walker: ctx->table_names[0] = tO
May 10 08:10:29 server pgpool[16693]: num_oids: 1 oid: 17762
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: realloc old size:0 new size:8192
May 10 08:10:29 server pgpool[16693]: pool_add_buffer: len:4, total:4 bufsize:8192
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: pool_unset_query_in_progress: done
May 10 08:10:29 server pgpool[16693]: ProcessBackendResponse: Ready For Query
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT  "tF".* FROM "tF" WHERE "tF"."property" = 'nip_state' ORDER BY property LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT  "tF".* FROM "tF" WHERE "tF"."property" = 'nip_state' ORDER BY property LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT  "tF".* FROM "tF" WHERE "tF"."property" = 'nip_state' ORDER BY property LIMIT 1dbname_production' -> `681c99545f5b3d3a117593bd6b2f77af'
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: search key ==681c99545f5b3d3a117593bd6b2f77af==
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: query=SELECT  "tF".* FROM "tF" WHERE "tF"."property" = 'nip_state' ORDER BY property LIMIT 1 len:246
May 10 08:10:29 server pgpool[16693]: send_cached_messages: T len: 167
May 10 08:10:29 server pgpool[16693]: send_message: kind=T, len=167, data=0x1b53975
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 63
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=63, data=0x1b53a1d
May 10 08:10:29 server pgpool[16693]: send_cached_messages: C len: 13
May 10 08:10:29 server pgpool[16693]: send_message: kind=C, len=13, data=0x1b53a5d
May 10 08:10:29 server pgpool[16693]: send_message: kind=Z, len=5, data=0x7fff08494ccf
May 10 08:10:29 server pgpool[16693]: query result fetched from cache. statement: SELECT  "tF".* FROM "tF" WHERE "tF"."property" = 'nip_state' ORDER BY property LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_fetch_from_memory_cache: a query result found in the query cache, SELECT  "tF".* FROM "tF" WHERE "tF"."property" = 'nip_state' ORDER BY property LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_set_skip_reading_from_backends: done
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT  "tB".* FROM "tB" WHERE "tB"."id" = 2231 ORDER BY tB.created_at DESC LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: username dbname
May 10 08:10:29 server pgpool[16693]: encode_key: database_name dbname_production
May 10 08:10:29 server pgpool[16693]: encode_key: query SELECT  "tB".* FROM "tB" WHERE "tB"."id" = 2231 ORDER BY tB.created_at DESC LIMIT 1
May 10 08:10:29 server pgpool[16693]: encode_key: `dbnameSELECT  "tB".* FROM "tB" WHERE "tB"."id" = 2231 ORDER BY tB.created_at DESC LIMIT 1dbname_production' -> `3219f48afa93b5fab70e54208ae09a8d'
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: search key ==3219f48afa93b5fab70e54208ae09a8d==
May 10 08:10:29 server pgpool[16693]: pool_fetch_cache: query=SELECT  "tB".* FROM "tB" WHERE "tB"."id" = 2231 ORDER BY tB.created_at DESC LIMIT 1 len:537
May 10 08:10:29 server pgpool[16693]: send_cached_messages: T len: 315
May 10 08:10:29 server pgpool[16693]: send_message: kind=T, len=315, data=0x1b546d5
May 10 08:10:29 server pgpool[16693]: send_cached_messages: D len: 206
May 10 08:10:29 server pgpool[16693]: send_message: kind=D, len=206, data=0x1b54811
May 10 08:10:29 server pgpool[16693]: send_cached_messages: C len: 13
May 10 08:10:29 server pgpool[16693]: send_message: kind=C, len=13, data=0x1b548e0
May 10 08:10:29 server pgpool[16693]: send_message: kind=Z, len=5, data=0x7fff08494ccf
May 10 08:10:29 server pgpool[16693]: query result fetched from cache. statement: SELECT  "tB".* FROM "tB" WHERE "tB"."id" = 2231 ORDER BY tB.created_at DESC LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_fetch_from_memory_cache: a query result found in the query cache, SELECT  "tB".* FROM "tB" WHERE "tB"."id" = 2231 ORDER BY tB.created_at DESC LIMIT 1
May 10 08:10:29 server pgpool[16693]: pool_set_skip_reading_from_backends: done
May 10 08:10:29 server pgpool[16693]: ProcessFrontendResponse: kind from frontend Q(51)
May 10 08:10:29 server pgpool[16693]: pool_unset_doing_extended_query_message: done
May 10 08:10:29 server pgpool[16693]: statement: SELECT  "tF".* FROM "tF" WHERE "tF"."property" = 'nip_state' ORDER BY property LIMIT 1
pgpool_bug_58_logs.txt (115,539 bytes)

wms

2013-05-14 03:16

reporter   ~0000275

Looks like I over-simplified what I was seeing in our logs. I have attached logs that seem to show the following query get cached and then not actually discarded even though the logs say it was.

SELECT "tB".* FROM "tB" WHERE "tB"."id" = 2231 ORDER BY tB.created_at DESC LIMIT 1

t-ishii

2013-05-14 11:46

developer   ~0000276

Can you please show a self contained test case? I have had hard times to reproduce the problem.

wms

2013-05-15 09:14

reporter   ~0000280

I am also having a hard time coming up with a reduced test case. Do you at least agree that the logs seem to show that query being pulled from the cache even though earlier in the log the cache was supposed to be discarded? I just can't figure out the exact pattern our app follows to trigger the behavior.

t-ishii

2013-05-15 09:25

developer   ~0000281

Yes. Although from your log I cannot see when the query cache for "SELECT "tB".* FROM "tB" WHERE "tB"."id" = 2231..." was created but I see UPDATE for tB was committed, thus the cache should have been discarded anyway. However after the commit "SELECT "tB".* FROM "tB" WHERE "tB"."id" = 2231..." returns the result from cache, and this should not happen.

wms

2013-05-17 04:48

reporter   ~0000284

Here are the queries to reproduce:


DROP TABLE IF EXISTS t1;
DROP TABLE IF EXISTS t2;

CREATE TABLE t1 (id integer NOT NULL, state integer);
CREATE SEQUENCE t1_seq START WITH 1 INCREMENT BY 1 NO MINVALUE NO MAXVALUE CACHE 1;
ALTER TABLE ONLY t1 ALTER COLUMN id SET DEFAULT nextval('t1_seq'::regclass);
ALTER TABLE ONLY t1 ADD CONSTRAINT t1_pkey PRIMARY KEY (id);

CREATE TABLE t2 (id integer NOT NULL, a_id integer NOT NULL);
CREATE SEQUENCE t2_seq START WITH 1 INCREMENT BY 1 NO MINVALUE NO MAXVALUE CACHE 1;
ALTER TABLE ONLY t2 ALTER COLUMN id SET DEFAULT nextval('t2_seq'::regclass);
ALTER TABLE ONLY t2 ADD CONSTRAINT t2_pkey PRIMARY KEY (id);

ALTER TABLE ONLY t2 ADD CONSTRAINT t2_a_id_fkey FOREIGN KEY (a_id) REFERENCES t1(id);

BEGIN;
INSERT INTO "t1" ("state") VALUES (0);
UPDATE "t1" SET "state" = 4 WHERE ("t1"."id" = 1);
INSERT INTO "t2" ("a_id") VALUES (1) RETURNING "id";
COMMIT;
BEGIN;
SELECT "t1".* FROM "t1" WHERE "t1"."id" = 1;
DELETE FROM "t2" WHERE ("t2"."id" > 0);
COMMIT;
BEGIN;
INSERT INTO "t2" ("a_id") VALUES (1) RETURNING "id";
SELECT "t2".* FROM "t2" WHERE ("t2".a_id = 1);
UPDATE "t1" SET "state" = 25 WHERE ("t1"."id" = 1);
COMMIT;
BEGIN;
SELECT "t1".* FROM "t1" WHERE "t1"."id" = 1;
COMMIT;


The last select should show the record having state=25, but it shows state=4. I can see state=25 if I connect directly to the backend.

t-ishii

2013-05-17 09:04

developer   ~0000285

Thanks for the test case. That helps a lot! It turned out that it's a pgpool's bug:
BEGIN;
INSERT INTO "t2" ("a_id") VALUES (1) RETURNING "id";
SELECT "t2".* FROM "t2" WHERE ("t2".a_id = 1);
UPDATE "t1" SET "state" = 25 WHERE ("t1"."id" = 1);
COMMIT;
At commit, pgpool tries to remove cache for t2 but it fails because in the same transaction the last statement was DML(UPDATE "t1"...).
(This sounds strange because the last DML was for t1, not t2. Yes, I know there's room to enhance but that is another story...)

After the failure pgpool mistakenly stops to invalidate cache for t1.
I have attached a fix. Can you please try it out?

t-ishii

2013-05-17 09:08

developer  

pool_memqcache.c.patch (404 bytes)
diff --git a/pool_memqcache.c b/pool_memqcache.c
index 65d7f97..d8ea1da 100644
--- a/pool_memqcache.c
+++ b/pool_memqcache.c
@@ -1483,7 +1483,7 @@ static void pool_invalidate_query_cache(int num_table_oids, int *table_oid, bool
 			 */
 			pool_debug("pool_invalidate_query_cache: failed to open %s. reason:%s",
 					   path, strerror(errno));
-			return;
+			continue;
 		}
 
 		fl.l_type   = F_RDLCK;

wms

2013-05-18 02:48

reporter   ~0000289

All of our tests pass now. Thanks for the quick fix.

Issue History

Date Modified Username Field Change
2013-05-08 08:51 wms New Issue
2013-05-08 08:53 wms Note Added: 0000268
2013-05-11 12:30 t-ishii Note Added: 0000269
2013-05-11 12:30 t-ishii Assigned To => t-ishii
2013-05-11 12:30 t-ishii Status new => assigned
2013-05-14 03:13 wms File Added: pgpool_bug_58_logs.txt
2013-05-14 03:16 wms Note Added: 0000275
2013-05-14 11:46 t-ishii Note Added: 0000276
2013-05-14 11:57 t-ishii Status assigned => feedback
2013-05-15 09:14 wms Note Added: 0000280
2013-05-15 09:14 wms Status feedback => assigned
2013-05-15 09:25 t-ishii Note Added: 0000281
2013-05-17 04:48 wms Note Added: 0000284
2013-05-17 09:04 t-ishii Note Added: 0000285
2013-05-17 09:08 t-ishii File Added: pool_memqcache.c.patch
2013-05-17 17:22 t-ishii Status assigned => feedback
2013-05-18 02:48 wms Note Added: 0000289
2013-05-18 02:48 wms Status feedback => assigned
2013-05-18 06:51 t-ishii Status assigned => resolved
2013-06-12 20:01 t-ishii Changeset attached => pgpool2 master 2b4b8370