statement_timeout doesn't work

[Sergey Konoplev <gray.ru@xxxxxxxxx>]

Hi,

PostgreSQL 9.2.7, Linux 2.6.32

Several days ago I found one of my servers out of connections,
pg_stat_activity showed that everything was waiting for the DROP/ALTER
INDEX transaction (see the record 2 below), that, as I guess, was
waiting for the function call (record 1).

  -[ RECORD 1 ]----------------------------------
  ts_age      | 00:07:15.52997
  state       | active
  query_age   | 00:07:15.529945
[...]
  waiting     | f
[...]
  query       | select foo(...)

  -[ RECORD 2 ]----------------------------------
  ts_age      | 00:06:37.844036
  state       | active
  query_age   | 00:06:37.844036
[...]
  waiting     | t
[...]
  query       | BEGIN;
SET LOCAL statement_timeout TO 1000;
DROP INDEX public.idx1;
ALTER INDEX public.idx2 RENAME TO idx1;
END;

The interesting thing is that the transaction sets local
statement_timeout to 1 second and its age was more than 6 minutes. The
foo() is a complex plpython function containing all the specter of mod
queries and using dblink(). I didn't manage to reproduce the problem
with a simple test.

psql -XAte <<EOF
\timing
CREATE LANGUAGE plpythonu;
CREATE TABLE test (t text);
CREATE INDEX test_idx ON test (t);
EOF
sleep 1
psql -XAte <<EOF &
\timing
CREATE OR REPLACE FUNCTION test_plpy()
RETURNS void LANGUAGE 'plpythonu' AS \$\$
import time
plpy.execute("INSERT INTO test VALUES ('a')")
plpy.execute("ALTER TABLE test ADD i integer")
plpy.execute("SELECT dblink_exec('dbname=grayhemp', 'DROP TABLE test')")
plpy.execute("SELECT * FROM dblink('', 'SELECT pg_sleep(3)') AS t (t text)")
\$\$;
SELECT test_plpy();
EOF
sleep 1
psql -XAte <<EOF
\timing
BEGIN;
SET LOCAL statement_timeout TO 1000;
DROP INDEX test_idx;
END;
EOF

Any ideas why could it happen and what should I do to prevent this in future?

-- 
Kind regards,
Sergey Konoplev
PostgreSQL Consultant and DBA

http://www.linkedin.com/in/grayhemp
+1 (415) 867-9984, +7 (499) 346-7196, +7 (988) 888-1979
gray.ru@xxxxxxxxx