[Pgpool-general] one of backends kicked after "VACUUM ANALYZE"

Sat May 14 09:13:55 UTC 2011

This is repeated asked question. See discussion:
http://lists.pgfoundry.org/pipermail/pgpool-general/2011-February/003460.html

Bottom line is, "you should not execute VACUUM via pgpool. Connect
PostgreSQL directry and execute VACUUM".

Probably I should add this to FAQ.
--
Tatsuo Ishii
SRA OSS, Inc. Japan
English: http://www.sraoss.co.jp/index_en.php
Japanese: http://www.sraoss.co.jp

> I removed a large number of records from a table (~38 mln out of ~40 mln), after which I've started "VACUUM VERBOSE ANALYZE my_table".
> 
> Near the very end, pgpool kicked one of the backends - is it expected? Please advise. I'm running pgpool-3.0.3.
> 
> (...)
> INFO:  index "core_extevent_protocol_id" now contains 1549814 row versions in 152408 pages
> DETAIL:  39686783 index row versions were removed.
> 146917 index pages have been deleted, 8965 are currently reusable.
> CPU 0.00s/0.00u sec elapsed 0.00 sec.
> INFO:  "core_extevent": found 443485 removable, 1549814 nonremovable row versions in 2707895 pages
> DETAIL:  0 dead row versions cannot be removed yet.
> There were 39320666 unused item pointers.
> 2649435 pages contain useful free space.
> 0 pages are entirely empty.
> CPU 101.70s/236.60u sec elapsed 3381.22 sec.
> WARNING:  relation "public.core_extevent" contains more than "max_fsm_pages" pages with useful free space
> HINT:  Consider using VACUUM FULL on this relation or increasing the configuration parameter "max_fsm_pages".
> INFO:  vacuuming "pg_toast.pg_toast_27375"
> INFO:  scanned index "pg_toast_27375_index" to remove 4 row versions
> DETAIL:  CPU 0.00s/0.00u sec elapsed 0.01 sec.
> INFO:  "pg_toast_27375": removed 4 row versions in 1 pages
> DETAIL:  CPU 0.00s/0.00u sec elapsed 0.02 sec.
> INFO:  index "pg_toast_27375_index" now contains 0 row versions in 2 pages
> DETAIL:  4 index row versions were removed.
> 0 index pages have been deleted, 0 are currently reusable.
> CPU 0.00s/0.00u sec elapsed 0.00 sec.
> ERROR:  kind mismatch among backends. Possible last query was: "VACUUM VERBOSE ANALYZE core_extevent;" kind details are: 0[N: "pg_toast_27375": found 4 removable, 0 nonremovable row versions in 1 pages] 1[C]
> HINT:  check data consistency among db nodes
> server closed the connection unexpectedly
> 	This probably means the server terminated abnormally
> 	before or while processing the request.
> The connection to the server was lost. Attempting reset: Succeeded.
> 
> 
> The "kicked" backend contains this - the only error I see there is "SGT ERROR:  canceling autovacuum task":
> 
> May 12 05:22:44 db20 postgres[27590]: [64-1] 2011-05-12 05:22:44 SGT INFO:  "core_extevent": found 36756505 removable, 1549821 nonremovable row versions in 2737848 pages
> May 12 05:22:44 db20 postgres[27590]: [64-2] 2011-05-12 05:22:44 SGT DETAIL:  0 dead row versions cannot be removed yet.
> May 12 05:22:44 db20 postgres[27590]: [64-3] #011There were 41727140 unused item pointers.
> May 12 05:22:44 db20 postgres[27590]: [64-4] #0112679731 pages contain useful free space.
> May 12 05:22:44 db20 postgres[27590]: [64-5] #0110 pages are entirely empty.
> May 12 05:22:44 db20 postgres[27590]: [64-6] #011CPU 86.00s/209.02u sec elapsed 1105.35 sec.
> May 12 05:22:44 db20 postgres[27590]: [65-1] 2011-05-12 05:22:44 SGT WARNING:  relation "public.core_extevent" contains more than "max_fsm_pages" pages with useful free
> May 12 05:22:44 db20 postgres[27590]: [65-2]  space
> May 12 05:22:44 db20 postgres[27590]: [65-3] 2011-05-12 05:22:44 SGT HINT:  Consider using VACUUM FULL on this relation or increasing the configuration parameter
> May 12 05:22:44 db20 postgres[27590]: [65-4]  "max_fsm_pages".
> May 12 05:22:44 db20 postgres[27590]: [65-5] 2011-05-12 05:22:44 SGT STATEMENT:  VACUUM VERBOSE ANALYZE core_extevent;
> May 12 05:22:44 db20 postgres[27590]: [66-1] 2011-05-12 05:22:44 SGT INFO:  vacuuming "pg_toast.pg_toast_27375"
> May 12 05:22:44 db20 postgres[27590]: [67-1] 2011-05-12 05:22:44 SGT INFO:  scanned index "pg_toast_27375_index" to remove 4 row versions
> May 12 05:22:44 db20 postgres[27590]: [67-2] 2011-05-12 05:22:44 SGT DETAIL:  CPU 0.00s/0.00u sec elapsed 0.00 sec.
> May 12 05:22:44 db20 postgres[27590]: [68-1] 2011-05-12 05:22:44 SGT INFO:  "pg_toast_27375": removed 4 row versions in 1 pages
> May 12 05:22:44 db20 postgres[27590]: [68-2] 2011-05-12 05:22:44 SGT DETAIL:  CPU 0.00s/0.00u sec elapsed 0.00 sec.
> May 12 05:22:44 db20 postgres[27590]: [69-1] 2011-05-12 05:22:44 SGT INFO:  index "pg_toast_27375_index" now contains 0 row versions in 2 pages
> May 12 05:22:44 db20 postgres[27590]: [69-2] 2011-05-12 05:22:44 SGT DETAIL:  4 index row versions were removed.
> May 12 05:22:44 db20 postgres[27590]: [69-3] #0110 index pages have been deleted, 0 are currently reusable.
> May 12 05:22:44 db20 postgres[27590]: [69-4] #011CPU 0.00s/0.00u sec elapsed 0.00 sec.
> May 12 05:22:44 db20 postgres[27590]: [70-1] 2011-05-12 05:22:44 SGT INFO:  "pg_toast_27375": found 4 removable, 0 nonremovable row versions in 1 pages
> May 12 05:22:44 db20 postgres[27590]: [70-2] 2011-05-12 05:22:44 SGT DETAIL:  0 dead row versions cannot be removed yet.
> May 12 05:22:44 db20 postgres[27590]: [70-3] #011There were 0 unused item pointers.
> May 12 05:22:44 db20 postgres[27590]: [70-4] #0111 pages contain useful free space.
> May 12 05:22:44 db20 postgres[27590]: [70-5] #0110 pages are entirely empty.
> May 12 05:22:44 db20 postgres[27590]: [70-6] #011CPU 0.00s/0.00u sec elapsed 0.02 sec.
> May 12 05:22:44 db20 postgres[27590]: [71-1] 2011-05-12 05:22:44 SGT INFO:  "pg_toast_27375": truncated 1 to 0 pages
> May 12 05:22:44 db20 postgres[27590]: [71-2] 2011-05-12 05:22:44 SGT DETAIL:  CPU 0.00s/0.00u sec elapsed 0.03 sec.
> May 12 05:22:45 db20 postgres[28283]: [2-1] 2011-05-12 05:22:45 SGT ERROR:  canceling autovacuum task
> May 12 05:22:45 db20 postgres[28283]: [2-2] 2011-05-12 05:22:45 SGT CONTEXT:  automatic vacuum of table "champion.public.core_extevent"
> May 12 05:22:45 db20 postgres[27590]: [72-1] 2011-05-12 05:22:45 SGT INFO:  analyzing "public.core_extevent"
> May 12 05:23:04 db20 postgres[27590]: [73-1] 2011-05-12 05:23:04 SGT INFO:  "core_extevent": scanned 3000 of 2737907 pages, containing 1493 live rows and 0 dead rows; 1493
> May 12 05:23:04 db20 postgres[27590]: [73-2]  rows in sample, 1362565 estimated total rows
> May 12 05:23:04 db20 postgres[27590]: [74-1] 2011-05-12 05:23:04 SGT LOG:  duration: 1126957.051 ms  statement: VACUUM VERBOSE ANALYZE core_extevent;
> 
> 
> -- 
> Tomasz Chmielewski
> http://wpkg.org
> 
> _______________________________________________
> Pgpool-general mailing list
> Pgpool-general at pgfoundry.org
> http://pgfoundry.org/mailman/listinfo/pgpool-general