Re: autovacuum process blocks without reporting a deadlock

On Nov 24, 2007 6:20 AM, Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> wrote:
> What other indexes does that table have?
>
> regards, tom lane
>

Hi,

last night it happend again. In the log-snippet u can see all indexes
of this table:

[9293 / 2007-11-26 21:46:28 CET]CONTEXT: SQL statement "UPDATE
hst_timerecording SET id_timerecording_join = NULL WHERE
id_timerecording_join = -1"
PL/pgSQL function "set_id_timerecording_join" line 121 at SQL statement
SQL statement "UPDATE hst_timerecording SET sales_volume =
NULL, sales_volume_commission = NULL WHERE business_day = $1 AND
id_employee = $2 "
PL/pgSQL function "compress_salaries_day" line 168 at SQL statement
SQL statement "SELECT compress_salaries_day( $1 , NULL, NULL)"
PL/pgSQL function "compress" line 460 at perform
[9293 / 2007-11-26 21:46:28 CET]LOCATION: exec_stmt_raise, pl_exec.c:2110
[9317 / 2007-11-26 21:46:34 CET]DEBUG: 00000: index
"hst_timerecording_business_day_idx" now contains 8640 row versions in
80 pages
[9317 / 2007-11-26 21:46:34 CET]DETAIL: 4469 index row versions were removed.
13 index pages have been deleted, 9 are currently reusable.
CPU 0.00s/0.00u sec elapsed 3.40 sec.
[9317 / 2007-11-26 21:46:34 CET]LOCATION: lazy_vacuum_index, vacuumlazy.c:736
[9317 / 2007-11-26 21:46:39 CET]DEBUG: 00000: index
"hst_timerecording_id_employee_idx" now contains 8640 row versions in
95 pages
[9317 / 2007-11-26 21:46:39 CET]DETAIL: 4469 index row versions were removed.
10 index pages have been deleted, 6 are currently reusable.
CPU 0.00s/0.00u sec elapsed 4.22 sec.
[9317 / 2007-11-26 21:46:39 CET]LOCATION: lazy_vacuum_index, vacuumlazy.c:736
[9317 / 2007-11-26 21:46:43 CET]DEBUG: 00000: index
"hst_timerecording_id_timerecording_idx" now contains 8640 row
versions in 97 pages
[9317 / 2007-11-26 21:46:43 CET]DETAIL: 4469 index row versions were removed.
11 index pages have been deleted, 5 are currently reusable.
CPU 0.00s/0.00u sec elapsed 4.40 sec.
[9317 / 2007-11-26 21:46:43 CET]LOCATION: lazy_vacuum_index, vacuumlazy.c:736

This are again the last log-entries of the blocking processes.
Obviously the three indexes where successful vacuumed?

I think this are the relevant pg_locks entries:

relation 75685778 75686189
9017862 25467 AccessShareLock f
relation 75685778 75686189
9009323 9317 ShareUpdateExclusiveLock
t
relation 75685778 75686189
9009312 9293 AccessShareLock t
relation 75685778 75686189
9009312 9293 RowExclusiveLock t
relation 75685778 75686189
9009312 9293 AccessExclusiveLock f
relation 75685778 75686189
9012978 28370 AccessShareLock f

75686189 is the table hst_timerecording. for me it looks like the
autovacuum is not releasing the blocking ShareUpdateExclusiveLock?

I hope this infos could help.

regards, t
thomas