Hi
I just noticed that some xpath queries can run inside libxml2 for a very
long time without responding to cancel requests (libxml2 v2.12.10, master).
As non-superuser:
psql (20devel)
Type "help" for help.
postgres=> set statement_timeout to '2s';
SET
postgres=> \timing on
Timing is on.
postgres=> select count(xpath('/a/node()', ('<a>' ||
repeat('x<![CDATA[y]]>', 30000) || g || '</a>')::xml)) from
generate_series(1, 2000) g;
ERROR: canceling statement due to statement timeout
Time: 13741,483 ms (00:13,741)
The statement seems to get cancelled only after libxml2 finishes
evaluating the xpath expression? Things get worse with a larger input:
psql (20devel)
Type "help" for help.
postgres=> select pg_backend_pid();
pg_backend_pid
----------------
279249
(1 row)
postgres=> select count(xpath('/a/node()', ('<a>' ||
repeat('x<![CDATA[y]]>', 4500000) || g || '</a>')::xml)) from
generate_series(1, 2000) g;
^CCancel request sent
^CCancel request sent
^CCancel request sent
The query cannot be cancelled. Killing the client or running
pg_terminate_backend() in another session won't help.
As a superuser:
psql (20devel)
Type "help" for help.
postgres=# select pg_terminate_backend(279249, 60000);
WARNING: backend with PID 279249 did not terminate within 60000
milliseconds
pg_terminate_backend
----------------------
f
(1 row)
postgres=# select pid, state, now() - query_start AS runtime from
pg_stat_activity where pid = 279249;
pid | state | runtime
--------+--------+-----------------
279249 | active | 00:58:08.844457
(1 row)
... which keeps one core at 100% and allocates ~2GB of memory. A kill -9
does the trick but takes the whole cluster with it :)
At first glance the issue appears to be in libxml2, but before I spend
too much time investigating it I'd like to ask if this is expected
behaviour or if it's worth chasing the root cause. WDYT?
Best, Jim
