[pgpool-general: 1710] Re: insert_lock hangs

Nozomi Anzai anzai at sraoss.co.jp
Thu May 9 18:33:35 JST 2013


Hi,

Could you tell us some hints to reproduce this?

- pgpool.conf
  - The mode do you use (replication mode, master slave mode with SR, etc.)
  - Using load balancing or not
- Steps you executed


> Hi!
> 
> We're running pgpool 3.2.x against two Postgresql 9.1.y servers under
> Debian 6 with several databases used by several distinct services like
> the ticket system OTRS.
> 
> With one of their last updates, they added SERIAL columns to some tables
> used in prepared statements, and now pgpool hangs when trying to
> executes those.
> 
> The OTRS system itself is "just" a bunch of perl scripts inside an
> Apache installation. When trying log into the ticket system, a
> session_id shall be written into a 'sessions' table, but this hangs:
> 
> pgpool.log:
> > 2013-05-06 14:22:02.235 CEST [13003] [unknown] 00000 LOG:  duration: 0.035 ms  statement: BEGIN
> > 2013-05-06 14:22:02.235 CEST [13003] [unknown] 00000 LOG:  duration: 0.070 ms  parse <unnamed>: 
> >                     DELETE FROM sessions
> >                     WHERE session_id = $1
> > 2013-05-06 14:22:02.236 CEST [13003] [unknown] 00000 LOG:  duration: 0.088 ms  bind <unnamed>: 
> >                     DELETE FROM sessions
> >                     WHERE session_id = $1
> > 2013-05-06 14:22:02.236 CEST [13003] [unknown] 00000 DETAIL:  parameters: $1 = '1eae4e7eb3f0adf2e2bc3f50f1446530f'
> > 2013-05-06 14:22:02.236 CEST [13003] [unknown] 00000 LOG:  duration: 0.063 ms  execute <unnamed>: 
> >                     DELETE FROM sessions
> >                     WHERE session_id = $1
> > 2013-05-06 14:22:02.236 CEST [13003] [unknown] 00000 DETAIL:  parameters: $1 = '1eae4e7eb3f0adf2e2bc3f50f1446530f'
> > 2013-05-06 14:22:02.236 CEST [13003] [unknown] 00000 LOG:  duration: 0.024 ms  statement: COMMIT
> > 2013-05-06 14:22:02.238 CEST [13003] [unknown] 00000 LOG:  duration: 0.426 ms  parse pgpool12980: 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('sessions')
> > 2013-05-06 14:22:02.238 CEST [13003] [unknown] 00000 LOG:  duration: 0.054 ms  bind pgpool12980/pgpool12980: 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('sessions')
> > 2013-05-06 14:22:02.239 CEST [13003] [unknown] 00000 LOG:  duration: 0.993 ms  execute pgpool12980/pgpool12980: 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('sessions')
> > 2013-05-06 14:22:02.240 CEST [13003] [unknown] 00000 LOG:  duration: 0.757 ms  parse pgpool12980: SELECT attname, d.adsrc, coalesce((d.adsrc LIKE '%now()%' OR d.adsrc LIKE '%''now''::text%') AND (a.atttypid = 'timestamp'::regtype::oid OR a.atttypid = 'timestamp with time zone'::regtype::oid OR a.atttypid = 'date'::regtype::oid OR a.atttypid = 'time'::regtype::oid OR a.atttypid = 'time with time zone'::regtype::oid) , false) FROM pg_catalog.pg_class c, pg_catalog.pg_attribute a  LEFT JOIN pg_catalog.pg_attrdef d ON (a.attrelid = d.adrelid AND a.attnum = d.adnum) WHERE c.oid = a.attrelid AND a.attnum >= 1 AND a.attisdropped = 'f' AND c.oid = pgpool_regclass('sessions') ORDER BY a.attnum
> > 2013-05-06 14:22:02.240 CEST [13003] [unknown] 00000 LOG:  duration: 0.087 ms  bind pgpool12980/pgpool12980: SELECT attname, d.adsrc, coalesce((d.adsrc LIKE '%now()%' OR d.adsrc LIKE '%''now''::text%') AND (a.atttypid = 'timestamp'::regtype::oid OR a.atttypid = 'timestamp with time zone'::regtype::oid OR a.atttypid = 'date'::regtype::oid OR a.atttypid = 'time'::regtype::oid OR a.atttypid = 'time with time zone'::regtype::oid) , false) FROM pg_catalog.pg_class c, pg_catalog.pg_attribute a  LEFT JOIN pg_catalog.pg_attrdef d ON (a.attrelid = d.adrelid AND a.attnum = d.adnum) WHERE c.oid = a.attrelid AND a.attnum >= 1 AND a.attisdropped = 'f' AND c.oid = pgpool_regclass('sessions') ORDER BY a.attnum
> > 2013-05-06 14:22:02.241 CEST [13003] [unknown] 00000 LOG:  duration: 0.787 ms  execute pgpool12980/pgpool12980: SELECT attname, d.adsrc, coalesce((d.adsrc LIKE '%now()%' OR d.adsrc LIKE '%''now''::text%') AND (a.atttypid = 'timestamp'::regtype::oid OR a.atttypid = 'timestamp with time zone'::regtype::oid OR a.atttypid = 'date'::regtype::oid OR a.atttypid = 'time'::regtype::oid OR a.atttypid = 'time with time zone'::regtype::oid) , false) FROM pg_catalog.pg_class c, pg_catalog.pg_attribute a  LEFT JOIN pg_catalog.pg_attrdef d ON (a.attrelid = d.adrelid AND a.attnum = d.adnum) WHERE c.oid = a.attrelid AND a.attnum >= 1 AND a.attisdropped = 'f' AND c.oid = pgpool_regclass('sessions') ORDER BY a.attnum
> > 2013-05-06 14:22:02.241 CEST [13003] [unknown] 00000 LOG:  duration: 0.026 ms  statement: BEGIN
> > 2013-05-06 14:22:02.263 CEST [13003] [unknown] 00000 LOG:  duration: 21.331 ms  parse pgpool12980: SELECT count(*) FROM pg_catalog.pg_class c JOIN pg_catalog.pg_namespace n ON (c.relnamespace = n.oid) WHERE nspname = 'pgpool_catalog' AND relname = 'insert_lock'
> > 2013-05-06 14:22:02.263 CEST [13003] [unknown] 00000 LOG:  duration: 0.067 ms  bind pgpool12980/pgpool12980: SELECT count(*) FROM pg_catalog.pg_class c JOIN pg_catalog.pg_namespace n ON (c.relnamespace = n.oid) WHERE nspname = 'pgpool_catalog' AND relname = 'insert_lock'
> > 2013-05-06 14:22:02.263 CEST [13003] [unknown] 00000 LOG:  duration: 0.038 ms  execute pgpool12980/pgpool12980: SELECT count(*) FROM pg_catalog.pg_class c JOIN pg_catalog.pg_namespace n ON (c.relnamespace = n.oid) WHERE nspname = 'pgpool_catalog' AND relname = 'insert_lock'
> > 2013-05-06 14:22:02.264 CEST [13003] [unknown] 00000 LOG:  duration: 0.231 ms  parse pgpool12980: SELECT 1 FROM pgpool_catalog.insert_lock WHERE reloid = pgpool_regclass('sessions') FOR UPDATE
> > 2013-05-06 14:22:02.264 CEST [13003] [unknown] 00000 LOG:  duration: 0.044 ms  bind pgpool12980/pgpool12980: SELECT 1 FROM pgpool_catalog.insert_lock WHERE reloid = pgpool_regclass('sessions') FOR UPDATE
> > 2013-05-06 14:22:02.267 CEST [13003] [unknown] 00000 LOG:  duration: 3.819 ms  execute pgpool12980/pgpool12980: SELECT 1 FROM pgpool_catalog.insert_lock WHERE reloid = pgpool_regclass('sessions') FOR UPDATE
> (… then nothing happens in this thread anymore.)
> 
> 
> The original hanging query isn't logged by pgpool, not even when turning
> on pgpool's extensive debug output, but running OTRS against postgresql
> directly (without pgpool) shows this as the offending query:
> > 2013-05-06 14:47:10.487 CEST [14141] [unknown] 00000 LOG:  duration: 0.068 ms  parse <unnamed>: INSERT INTO sessions (session_id, data_key, data_value, serialized) VALUES ($1,$2,$3,$4)
> > 2013-05-06 14:47:10.487 CEST [14141] [unknown] 00000 LOG:  duration: 0.045 ms  bind <unnamed>: INSERT INTO sessions (session_id, data_key, data_value, serialized) VALUES ($1,$2,$3,$4)
> > 2013-05-06 14:47:10.487 CEST [14141] [unknown] 00000 DETAIL:  parameters: $1 = '11a98dce334f5dd318594a76edf08819b', $2 = 'LastScreenOverview', $3 = 'Action=AgentTicketQueue;QueueID=9;View=', $4 = '0'
> > 2013-05-06 14:47:10.487 CEST [14141] [unknown] 00000 LOG:  duration: 0.106 ms  execute <unnamed>: INSERT INTO sessions (session_id, data_key, data_value, serialized) VALUES ($1,$2,$3,$4)
> > 2013-05-06 14:47:10.487 CEST [14141] [unknown] 00000 DETAIL:  parameters: $1 = '11a98dce334f5dd318594a76edf08819b', $2 = 'LastScreenOverview', $3 = 'Action=AgentTicketQueue;QueueID=9;View=', $4 = '0'
> 
> The context of this query suggests that no other query is using/blocking
> pgpool's insert_lock table at this moment, especially not for
> minutes/hours, hence I'm quite at a loss here.
> The problem exists both with pgpool 3.2.1 and 3.2.3.
> 
> Any suggestions what might be the problem?
> I can provide pgpool debug output if needed.
> 
> 
> Karsten
> _______________________________________________
> pgpool-general mailing list
> pgpool-general �� pgpool.net
> http://www.pgpool.net/mailman/listinfo/pgpool-general


-- 
Nozomi Anzai
SRA OSS, Inc. Japan


More information about the pgpool-general mailing list