[pgpool-general: 3801] PgPool Cache not getting invalidated even after insert

Sat Jun 13 15:08:28 JST 2015

Hi,
I am using pgpool 3.4  talking to the database with 2 slaves and one master. Apparently I have an application servers connecting to the database using pgpool through hibernate. Unfortunately the pgpool cache does not gets  invalidated even after the insert followed by commit. We have autocomit false at hibernate layer.  Intersting to note that this happens with merge operation in hibernate. I have pasted the log here, with important statements in RED.
Appreciate if some body can help here.
Regards,
Sajeev

###Hibernate merge operation - (select) followed by insert####################
2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: Parse: SET extra_float_digits = 32015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: Parse: SET extra_float_digits = 32015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: B message2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: B message2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: Execute: SET extra_float_digits = 32015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: Execute: SET extra_float_digits = 32015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: Parse: BEGIN2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: Parse: BEGIN2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: B message2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: B message2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: Execute: BEGIN2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: Execute: BEGIN2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.relname = 'pg_namespace'2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: SELECT count(*) from (SELECT has_function_privilege('postgres', 'to_regclass(cstring)', 'execute') WHERE EXISTS(SELECT * FROM pg_catalog.pg_proc AS p WHERE p.proname = 'to_regclass')) AS s2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: SELECT count(*) from (SELECT has_function_privilege('postgres', 'pgpool_regclass(cstring)', 'execute') WHERE EXISTS(SELECT * FROM pg_catalog.pg_proc AS p WHERE p.proname = 'pgpool_regclass')) AS s2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE c.oid = pgpool_regclass('permalink') AND c.relnamespace = n.oid AND n.nspname = 'pg_catalog'2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = pgpool_regclass('permalink') AND (c.relkind = 'v' OR c.relkind = 'm')2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: SELECT count(*) FROM pg_catalog.pg_class AS c, pg_catalog.pg_attribute AS a WHERE c.relname = 'pg_class' AND a.attrelid = c.oid AND a.attname = 'relpersistence'2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = pgpool_regclass('permalink') AND c.relpersistence = 'u'2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: Parse: select permalink0_.id as id1_35_, permalink0_.create_time as create2_35_, permalink0_.last_update_time as last3_35_, permalink0_.expiry_date as expiry4_35_, permalink0_.link_data as link5_35_, permalink0_.link_type as link6_35_, permalink0_.lookup_hash as lookup7_35_ from permalink permalink0_ where permalink0_.link_type=$1 and permalink0_.lookup_hash=$22015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: B message2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: D message2015-06-12 18:27:05: pid 24262: LOG:  fetch from memory cache
2015-06-12 18:27:05: pid 24262: DETAIL:  query result fetched from cache. statement: select permalink0_.id as id1_35_, permalink0_.create_time as create2_35_, permalink0_.last_update_time as last3_35_, permalink0_.expiry_date as expiry4_35_, permalink0_.link_data as link5_35_, permalink0_.link_type as link6_35_, permalink0_.lookup_hash as lookup7_35_ from permalink permalink0_ where permalink0_.link_type=$1 and permalink0_.lookup_hash=$2 000200000000000200000045636F6D2E666972656579652E686F737465642E6D6F62696C652E64616F2E6D6F64656C2E7065726D616C696E6B2E4D5053417070416E616C797369735065726D614C696E6B0000000834373034383338310000
2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: Parse: select permalink0_.id as id1_35_0_, permalink0_.create_time as create2_35_0_, permalink0_.last_update_time as last3_35_0_, permalink0_.expiry_date as expiry4_35_0_, permalink0_.link_data as link5_35_0_, permalink0_.link_type as link6_35_0_, permalink0_.lookup_hash as lookup7_35_0_ from permalink permalink0_ where permalink0_.id=$12015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: B message2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: D message2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: Execute: select permalink0_.id as id1_35_0_, permalink0_.create_time as create2_35_0_, permalink0_.last_update_time as last3_35_0_, permalink0_.expiry_date as expiry4_35_0_, permalink0_.link_data as link5_35_0_, permalink0_.link_type as link6_35_0_, permalink0_.lookup_hash as lookup7_35_0_ from permalink permalink0_ where permalink0_.id=$12015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: SELECT pgpool_regclass('permalink')2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: SELECT count(*) FROM pg_catalog.pg_attrdef AS d, pg_catalog.pg_class AS c WHERE d.adrelid = c.oid AND d.adsrc ~ 'nextval' AND c.oid = pgpool_regclass('permalink')
2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: Parse: insert into permalink (create_time, last_update_time, expiry_date, link_data, link_type, lookup_hash, id) values ($1, $2, $3, $4, $5, $6, $7)
2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: B message2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: D message
2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: Execute: insert into permalink (create_time, last_update_time, expiry_date, link_data, link_type, lookup_hash, id) values ($1, $2, $3, $4, $5, $6, $7)2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: Parse: COMMIT2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: Parse: COMMIT2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: B message2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: B message2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: Execute: COMMIT2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement: Execute: COMMIT2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement: SELECT oid FROM pg_database WHERE datname = 'mobile_app'2015-06-12 18:27:05: pid 24262: LOG:  statement:  DISCARD ALL2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 0 backend pid: 13351 statement:  DISCARD ALL2015-06-12 18:27:05: pid 24262: LOG:  DB node id: 1 backend pid: 21131 statement:  DISCARD ALL

####separate connection select for inserted id################
2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 0 backend pid: 13336 statement: Parse: SET extra_float_digits = 32015-06-12 18:27:42: pid 24289: LOG:  DB node id: 1 backend pid: 21117 statement: Parse: SET extra_float_digits = 32015-06-12 18:27:42: pid 24289: LOG:  DB node id: 0 backend pid: 13336 statement: B message2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 1 backend pid: 21117 statement: B message2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 0 backend pid: 13336 statement: Execute: SET extra_float_digits = 32015-06-12 18:27:42: pid 24289: LOG:  DB node id: 1 backend pid: 21117 statement: Execute: SET extra_float_digits = 32015-06-12 18:27:42: pid 24289: LOG:  DB node id: 0 backend pid: 13336 statement: Parse: BEGIN2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 1 backend pid: 21117 statement: Parse: BEGIN2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 0 backend pid: 13336 statement: B message2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 1 backend pid: 21117 statement: B message2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 0 backend pid: 13336 statement: Execute: BEGIN2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 1 backend pid: 21117 statement: Execute: BEGIN2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 0 backend pid: 13336 statement: SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE c.oid = pgpool_regclass('permalink') AND c.relnamespace = n.oid AND n.nspname = 'pg_catalog'2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 0 backend pid: 13336 statement: SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = pgpool_regclass('permalink') AND (c.relkind = 'v' OR c.relkind = 'm')2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 0 backend pid: 13336 statement: SELECT count(*) FROM pg_catalog.pg_class AS c, pg_catalog.pg_attribute AS a WHERE c.relname = 'pg_class' AND a.attrelid = c.oid AND a.attname = 'relpersistence'2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 0 backend pid: 13336 statement: SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = pgpool_regclass('permalink') AND c.relpersistence = 'u'2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 1 backend pid: 21117 statement: Parse: select permalink0_.id as id1_35_0_, permalink0_.create_time as create2_35_0_, permalink0_.last_update_time as last3_35_0_, permalink0_.expiry_date as expiry4_35_0_, permalink0_.link_data as link5_35_0_, permalink0_.link_type as link6_35_0_, permalink0_.lookup_hash as lookup7_35_0_ from permalink permalink0_ where permalink0_.id=$12015-06-12 18:27:42: pid 24289: LOG:  DB node id: 1 backend pid: 21117 statement: B message2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 1 backend pid: 21117 statement: D message
2015-06-12 18:27:42: pid 24289: LOG:  fetch from memory cache2015-06-12 18:27:42: pid 24289: DETAIL:  query result fetched from cache. statement: select permalink0_.id as id1_35_0_, permalink0_.create_time as create2_35_0_, permalink0_.last_update_time as last3_35_0_, permalink0_.expiry_date as expiry4_35_0_, permalink0_.link_data as link5_35_0_, permalink0_.link_type as link6_35_0_, permalink0_.lookup_hash as lookup7_35_0_ from permalink permalink0_ where permalink0_.id=$1 00010001000100000010885E21CF35C64884B35BF3AA2BDC05110000
2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 0 backend pid: 13336 statement: Parse: COMMIT2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 1 backend pid: 21117 statement: Parse: COMMIT2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 0 backend pid: 13336 statement: B message2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 1 backend pid: 21117 statement: B message2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 0 backend pid: 13336 statement: Execute: COMMIT2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 1 backend pid: 21117 statement: Execute: COMMIT2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 0 backend pid: 13336 statement: SELECT oid FROM pg_database WHERE datname = 'mobile_app'2015-06-12 18:27:42: pid 24289: LOG:  statement:  DISCARD ALL2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 0 backend pid: 13336 statement:  DISCARD ALL2015-06-12 18:27:42: pid 24289: LOG:  DB node id: 1 backend pid: 21117 statement:  DISCARD ALL
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.sraoss.jp/pipermail/pgpool-general/attachments/20150613/8fac6b17/attachment-0001.html>