Use of uninitialized value $to_page

[DenisBY]

Hi,

I have following error for a few tables:

Mon Sep  8 09:31:12 2014 zabbix, partitions.history_p2014_06_16 INFO Vacuum initial: 20512 pages left, duration 1.794 seconds.
Mon Sep  8 09:31:12 2014 zabbix, partitions.history_p2014_06_16 NOTICE Statistics: 20512 pages (32901 pages including toasts and indexes), approximately 7.94% (1629 pages) can be compacted reducing the size by 13 MB.
Mon Sep  8 09:31:12 2014 zabbix, partitions.history_p2014_06_16 INFO Update by column: ns.
Mon Sep  8 09:31:12 2014 zabbix, partitions.history_p2014_06_16 INFO Set pages/round: 10.
Mon Sep  8 09:31:12 2014 zabbix, partitions.history_p2014_06_16 INFO Set pages/vacuum: 1000.
Mon Sep  8 09:31:12 2014 zabbix, partitions.history_p2014_06_16 WARNING Incorrect result of cleaning: column_ident ns, to_page 20511, pages_per_round 10, max_tupples_per_page 316.
Use of uninitialized value $to_page in subtraction (-) at /loader/0x25deef0/PgToolkit/Compactor/Table.pm line 456, <GEN8> line 8.
Mon Sep  8 09:31:13 2014 zabbix, partitions.history_p2014_06_16 INFO Cleaning in average: 196.0 pages/second (0.051 seconds per 10 pages).
Use of uninitialized value $arg_hash{"to_page"} in addition (+) at /loader/0x25deef0/PgToolkit/Compactor/Table.pm line 855, <GEN8> line 8.
Use of uninitialized value $arg_hash{"to_page"} in addition (+) at /loader/0x25deef0/PgToolkit/Compactor/Table.pm line 857, <GEN8> line 8.
Use of uninitialized value $arg_hash{"to_page"} in subtraction (-) at /loader/0x25deef0/PgToolkit/Compactor/Table.pm line 865, <GEN8> line 8.
Mon Sep  8 09:31:13 2014 zabbix, partitions.history_p2014_06_16 NOTICE Vacuum routine: can not clean 20511 pages, 20512 pages left, duration 0.139 seconds.
Use of uninitialized value $to_page in numeric ge (>=) at /loader/0x25deef0/PgToolkit/Compactor/Table.pm line 492, <GEN8> line 8.
Use of uninitialized value $to_page in numeric le (<=) at /loader/0x25deef0/PgToolkit/Compactor/Table.pm line 496, <GEN8> line 8.
Mon Sep  8 09:31:15 2014 zabbix, partitions.history_p2014_06_16 INFO Analyze final: duration 2.074 second.
Mon Sep  8 09:31:15 2014 zabbix, partitions.history_p2014_06_16 WARNING Processing incomplete.
Mon Sep  8 09:31:15 2014 zabbix, partitions.history_p2014_06_16 NOTICE Processing results: 20512 pages left (32901 pages including toasts and indexes), size reduced by 0 bytes (0 bytes including toasts and indexes) in total, approximately 7.90% (1620 pages) that is 13 MB more were expected to be compacted after this attempt.

[grayhemp]

Hi,

What version do you use, how did you clonned/checkout/installed and run it?

[DenisBY]

Hi,

I'm using master branch cloned few days ago. Did 'git pull' few minutes ago. Lets see what changed.
I'm using the following cron entry:

0 0 * * *       /usr/local/bin/pgcompact --dbname zabbix --reindex -q --min-free-percent 7

/usr/local/bin/pgcompact is a symlink to the /usr/local/pgtoolkit/fatpack/pgcompact

[DenisBY]

Same problem with today's pull:

Wed Sep 10 08:48:28 2014 zabbix, partitions.history_p2014_07_28 INFO Vacuum initial: 14771 pages left, duration 1.340 seconds.
Wed Sep 10 08:48:28 2014 zabbix, partitions.history_p2014_07_28 NOTICE Statistics: 14771 pages (23691 pages including toasts and indexes), approximately 7.99% (1180 pages) can be compacted reducing the size by 9440 kB.
Wed Sep 10 08:48:28 2014 zabbix, partitions.history_p2014_07_28 INFO Update by column: ns.
Wed Sep 10 08:48:28 2014 zabbix, partitions.history_p2014_07_28 INFO Set pages/round: 10.
Wed Sep 10 08:48:28 2014 zabbix, partitions.history_p2014_07_28 INFO Set pages/vacuum: 924.
Wed Sep 10 08:48:28 2014 zabbix, partitions.history_p2014_07_28 WARNING Incorrect result of cleaning: column_ident ns, to_page 14770, pages_per_round 10, max_tupples_per_page 316.
Use of uninitialized value $to_page in subtraction (-) at /loader/0xbafef0/PgToolkit/Compactor/Table.pm line 456, <GEN8> line 8.
Wed Sep 10 08:48:28 2014 zabbix, partitions.history_p2014_07_28 INFO Cleaning in average: 243.9 pages/second (0.041 seconds per 10 pages).
Use of uninitialized value $arg_hash{"to_page"} in addition (+) at /loader/0xbafef0/PgToolkit/Compactor/Table.pm line 855, <GEN8> line 8.
Use of uninitialized value $arg_hash{"to_page"} in addition (+) at /loader/0xbafef0/PgToolkit/Compactor/Table.pm line 857, <GEN8> line 8.
Use of uninitialized value $arg_hash{"to_page"} in subtraction (-) at /loader/0xbafef0/PgToolkit/Compactor/Table.pm line 865, <GEN8> line 8.
Wed Sep 10 08:48:28 2014 zabbix, partitions.history_p2014_07_28 NOTICE Vacuum routine: can not clean 14770 pages, 14771 pages left, duration 0.121 seconds.
Use of uninitialized value $to_page in numeric ge (>=) at /loader/0xbafef0/PgToolkit/Compactor/Table.pm line 492, <GEN8> line 8.
Use of uninitialized value $to_page in numeric le (<=) at /loader/0xbafef0/PgToolkit/Compactor/Table.pm line 496, <GEN8> line 8.
Wed Sep 10 08:48:30 2014 zabbix, partitions.history_p2014_07_28 INFO Analyze final: duration 1.585 second.
Wed Sep 10 08:48:30 2014 zabbix, partitions.history_p2014_07_28 WARNING Processing incomplete.
Wed Sep 10 08:48:30 2014 zabbix, partitions.history_p2014_07_28 NOTICE Processing results: 14771 pages left (23691 pages including toasts and indexes), size reduced by 0 bytes (0 bytes including toasts and indexes) in total, approximately 7.93% (1171 pages) that is 9368 kB more were expected to be compacted after this attempt.

[grayhemp]

On Wed, Sep 10, 2014 at 1:25 AM, Denis notifications@github.com wrote:

I'm using master branch cloned few days ago. Did 'git pull' few minutes ago. Lets see what changed.

You shouldn't use the master branch as it is currently used for
development purposes and is not stable. Use the latest stable version
insted:

https://github.com/grayhemp/pgtoolkit/releases/tag/v1.0.1

ps. I should probably change my branching policy to keep the latest
stable one under the master branch to not confuse people.

I'm using the following cron entry:

0 0 * * * /usr/local/bin/pgcompact --dbname zabbix --reindex -q --min-free-percent 7

/usr/local/bin/pgcompact is a symlink to the /usr/local/pgtoolkit/fatpack/pgcompact

—
Reply to this email directly or view it on GitHub.

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@gmail.com

[DenisBY]

Same problem with 1.0.1:

root@zabbix-server:/usr/local/pgtoolkit# git checkout tags/v1.0.1
Note: checking out 'tags/v1.0.1'.

You are in 'detached HEAD' state. You can look around, make experimental
changes and commit them, and you can discard any commits you make in this
state without impacting any branches by performing another checkout.

If you want to create a new branch to retain commits you create, you may
do so (now or later) by using -b with the checkout command again. Example:

  git checkout -b new_branch_name

HEAD is now at b9c0395... Rebuilt the fatpacked version.
root@zabbix-server:/usr/local/pgtoolkit# fatpack/pgcompact --version
pgcompact (PgToolkit) v1.0.1

Thu Sep 11 07:00:02 2014 zabbix, partitions.history_p2014_07_28 INFO Vacuum initial: 14771 pages left, duration 1.434 seconds.
Thu Sep 11 07:00:02 2014 zabbix, partitions.history_p2014_07_28 NOTICE Statistics: 14771 pages (23691 pages including toasts and indexes), approximately 7.99% (1180 pages) can be compacted reducing the size by 9440 kB.
Thu Sep 11 07:00:02 2014 zabbix, partitions.history_p2014_07_28 INFO Update by column: ns.
Thu Sep 11 07:00:02 2014 zabbix, partitions.history_p2014_07_28 INFO Set pages/round: 10.
Thu Sep 11 07:00:02 2014 zabbix, partitions.history_p2014_07_28 INFO Set pages/vacuum: 924.
Thu Sep 11 07:00:02 2014 zabbix, partitions.history_p2014_07_28 WARNING Incorrect result of cleaning: column_ident ns, to_page 14770, pages_per_round 10, max_tupples_per_page 316.
Use of uninitialized value $to_page in subtraction (-) at /loader/0x128bef0/PgToolkit/Compactor/Table.pm line 456, <GEN8> line 7.
Thu Sep 11 07:00:02 2014 zabbix, partitions.history_p2014_07_28 INFO Cleaning in average: 231.0 pages/second (0.043 seconds per 10 pages).
Use of uninitialized value $arg_hash{"to_page"} in addition (+) at /loader/0x128bef0/PgToolkit/Compactor/Table.pm line 855, <GEN8> line 7.
Use of uninitialized value $arg_hash{"to_page"} in addition (+) at /loader/0x128bef0/PgToolkit/Compactor/Table.pm line 857, <GEN8> line 7.
Use of uninitialized value $arg_hash{"to_page"} in subtraction (-) at /loader/0x128bef0/PgToolkit/Compactor/Table.pm line 865, <GEN8> line 7.
Thu Sep 11 07:00:02 2014 zabbix, partitions.history_p2014_07_28 NOTICE Vacuum routine: can not clean 14770 pages, 14771 pages left, duration 0.121 seconds.
Use of uninitialized value $to_page in numeric ge (>=) at /loader/0x128bef0/PgToolkit/Compactor/Table.pm line 492, <GEN8> line 7.
Use of uninitialized value $to_page in numeric le (<=) at /loader/0x128bef0/PgToolkit/Compactor/Table.pm line 496, <GEN8> line 7.
Thu Sep 11 07:00:04 2014 zabbix, partitions.history_p2014_07_28 INFO Analyze final: duration 1.780 second.
Thu Sep 11 07:00:04 2014 zabbix, partitions.history_p2014_07_28 WARNING Processing incomplete.
Thu Sep 11 07:00:04 2014 zabbix, partitions.history_p2014_07_28 NOTICE Processing results: 14771 pages left (23691 pages including toasts and indexes), size reduced by 0 bytes (0 bytes including toasts and indexes) in total, approximately 7.93% (1171 pages) that is 9368 kB more were expected to be compacted after this attempt.

BTW. There is also small issue on info verbosity level:

Thu Sep 11 06:48:37 2014 zabbix, public.triggers NOTICE Reindex queries: public.triggers_pkey, initial size 44 pages (352 kB).
REINDEX INDEX public.triggers_pkey; -- zabbix
Thu Sep 11 06:48:37 2014 zabbix, public.triggers NOTICE Processing complete.
...
Thu Sep 11 06:48:38 2014 zabbix, public.events NOTICE Reindex queries: public.events_pkey, initial size 510 pages (4080 kB).
REINDEX INDEX public.events_pkey; -- zabbix
Thu Sep 11 06:48:39 2014 zabbix, public.events INFO Reindex: public.events_2, initial size 687 pages (5496 kB), has been reduced by 0% (8192 bytes), duration 0.421 seconds, attempts 1.

Didn't see it with master so I guess it has been fixed already.

P.S. Можем использовать русский если здесь это принято :)

[grayhemp]

P.S. Можем использовать русский если здесь это принято :)

Конечно :)

On Thu, Sep 11, 2014 at 12:04 AM, Denis notifications@github.com wrote:

Same problem with 1.0.1:

Thu Sep 11 07:00:02 2014 zabbix, partitions.history_p2014_07_28 INFO Vacuum initial: 14771 pages left, duration 1.434 seconds.
Thu Sep 11 07:00:02 2014 zabbix, partitions.history_p2014_07_28 NOTICE Statistics: 14771 pages (23691 pages including toasts and indexes), approximately 7.99% (1180 pages) can be compacted reducing the size by 9440 kB.
Thu Sep 11 07:00:02 2014 zabbix, partitions.history_p2014_07_28 INFO Update by column: ns.
Thu Sep 11 07:00:02 2014 zabbix, partitions.history_p2014_07_28 INFO Set pages/round: 10.
Thu Sep 11 07:00:02 2014 zabbix, partitions.history_p2014_07_28 INFO Set pages/vacuum: 924.
Thu Sep 11 07:00:02 2014 zabbix, partitions.history_p2014_07_28 WARNING Incorrect result of cleaning: column_ident ns, to_page 14770, pages_per_round 10, max_tupples_per_page 316.
Use of uninitialized value $to_page in subtraction (-) at /loader/0x128bef0/PgToolkit/Compactor/Table.pm line 456, line 7.

Хм.. как интересно, т.е. ситуация воспроизводится. А можно с -v debug1
запустить и посмотреть результат?

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@gmail.com

[DenisBY]

Thu Sep 11 08:01:40 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.001s, statement: 
SELECT pg_try_advisory_lock(
        'pg_catalog.pg_class'::regclass::integer,
        'partitions.history_p2014_07_28'::regclass::integer)::integer;

Thu Sep 11 08:01:40 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.011s, statement: 
SELECT
    size,
    total_size,
    ceil(size::real / bs) AS page_count,
    ceil(total_size::real / bs) AS total_page_count
FROM (
    SELECT
        current_setting('block_size')::integer AS bs,
        pg_catalog.pg_relation_size('partitions.history_p2014_07_28') AS size,
        pg_catalog.pg_total_relation_size('partitions.history_p2014_07_28') AS total_size
) AS sq

Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.922s, statement: 
VACUUM partitions.history_p2014_07_28
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.002s, statement: 
SELECT
    size,
    total_size,
    ceil(size::real / bs) AS page_count,
    ceil(total_size::real / bs) AS total_page_count
FROM (
    SELECT
        current_setting('block_size')::integer AS bs,
        pg_catalog.pg_relation_size('partitions.history_p2014_07_28') AS size,
        pg_catalog.pg_total_relation_size('partitions.history_p2014_07_28') AS total_size
) AS sq

Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 INFO Vacuum initial: 14771 pages left, duration 0.922 seconds.
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.019s, statement: 
SELECT
    ceil(pure_page_count * 100 / fillfactor) AS effective_page_count,
    CASE WHEN size::real > 0 THEN
        round(
            100 * (
                1 - (pure_page_count * 100 / fillfactor) / (size::real / bs)
            )::numeric, 2
        )
    ELSE 0 END AS free_percent,
    ceil(size::real - bs * pure_page_count * 100 / fillfactor) AS free_space
FROM (
    SELECT
        bs, size, fillfactor,
        ceil(
            reltuples * (
                max(stanullfrac) * ma * ceil(
                    (
                        ma * ceil(
                            (
                                header_width +
                                ma * ceil(count(1)::real / ma)
                            )::real / ma
                        ) + sum((1 - stanullfrac) * stawidth)
                    )::real / ma
                ) +
                (1 - max(stanullfrac)) * ma * ceil(
                    (
                        ma * ceil(header_width::real / ma) +
                        sum((1 - stanullfrac) * stawidth)
                    )::real / ma
                )
            )::real / (bs - 24)
        ) AS pure_page_count
    FROM (
        SELECT
            pg_catalog.pg_class.oid AS class_oid,
            reltuples,
            23 AS header_width, 8 AS ma,
            current_setting('block_size')::integer AS bs,
            pg_catalog.pg_relation_size(pg_catalog.pg_class.oid) AS size,
            coalesce(
                (
                    SELECT (
                        regexp_matches(
                            reloptions::text, E'.*fillfactor=(\\d+).*'))[1]),
                '100')::real AS fillfactor
        FROM pg_catalog.pg_class
        WHERE pg_catalog.pg_class.oid = 'partitions.history_p2014_07_28'::regclass
    ) AS const
    LEFT JOIN pg_catalog.pg_statistic ON starelid = class_oid
    GROUP BY bs, class_oid, fillfactor, ma, size, reltuples, header_width
) AS sq

Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 NOTICE Statistics: 14771 pages (23691 pages including toasts and indexes), approximately 7.99% (1180 pages) can be compacted reducing the size by 9440 kB.
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.001s, statement: 
SELECT count(1) FROM pg_catalog.pg_trigger
WHERE
    tgrelid = 'partitions.history_p2014_07_28'::regclass AND
    tgenabled IN ('A', 'R') AND
    (tgtype & 16)::boolean

Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.001s, statement: 
SELECT attname
FROM pg_catalog.pg_attribute
WHERE
    attnum > 0 AND -- neither system
    NOT attisdropped AND -- nor dropped
    attrelid = 'partitions.history_p2014_07_28'::regclass
ORDER BY
    -- Variable legth attributes have lower priority because of the chance
    -- of being toasted
    (attlen = -1),
    -- Preferably not indexed attributes
    (
        attnum::text IN (
            SELECT regexp_split_to_table(indkey::text, ' ')
            FROM pg_catalog.pg_index
            WHERE indrelid = 'partitions.history_p2014_07_28'::regclass)),
    -- Preferably smaller attributes
    attlen,
    attnum
LIMIT 1;

Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.001s, statement: 
SELECT ceil(current_setting('block_size')::real / sum(attlen))
FROM pg_catalog.pg_attribute
WHERE
    attrelid = 'partitions.history_p2014_07_28'::regclass AND
    attnum < 0;

Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 INFO Update by column: ns.
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 INFO Set pages/round: 10.
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 INFO Set pages/vacuum: 924.
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG1 Executed SQL: duration 0.001s, statement: 
BEGIN;
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG1 Executed SQL: duration 0.042s, statement: 
SELECT public.pgcompact_clean_pages_7473(
    'partitions.history_p2014_07_28', 'ns', 14770,
    10, 316)

Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 WARNING Incorrect result of cleaning: column_ident ns, to_page 14770, pages_per_round 10, max_tupples_per_page 316.
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG1 Executed SQL: duration 0.001s, statement: 
COMMIT;
Use of uninitialized value $to_page in subtraction (-) at /loader/0xc66ef0/PgToolkit/Compactor/Table.pm line 456, <GEN8> line 6.
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 INFO Cleaning in average: 236.8 pages/second (0.042 seconds per 10 pages).
Thu Sep 11 08:01:42 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.119s, statement: 
VACUUM partitions.history_p2014_07_28
Thu Sep 11 08:01:42 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.001s, statement: 
SELECT
    size,
    total_size,
    ceil(size::real / bs) AS page_count,
    ceil(total_size::real / bs) AS total_page_count
FROM (
    SELECT
        current_setting('block_size')::integer AS bs,
        pg_catalog.pg_relation_size('partitions.history_p2014_07_28') AS size,
        pg_catalog.pg_total_relation_size('partitions.history_p2014_07_28') AS total_size
) AS sq

Use of uninitialized value $arg_hash{"to_page"} in addition (+) at /loader/0xc66ef0/PgToolkit/Compactor/Table.pm line 855, <GEN8> line 6.
Use of uninitialized value $arg_hash{"to_page"} in addition (+) at /loader/0xc66ef0/PgToolkit/Compactor/Table.pm line 857, <GEN8> line 6.
Use of uninitialized value $arg_hash{"to_page"} in subtraction (-) at /loader/0xc66ef0/PgToolkit/Compactor/Table.pm line 865, <GEN8> line 6.
Thu Sep 11 08:01:42 2014 zabbix, partitions.history_p2014_07_28 NOTICE Vacuum routine: can not clean 14770 pages, 14771 pages left, duration 0.119 seconds.
Use of uninitialized value $to_page in numeric ge (>=) at /loader/0xc66ef0/PgToolkit/Compactor/Table.pm line 492, <GEN8> line 6.
Use of uninitialized value $to_page in numeric le (<=) at /loader/0xc66ef0/PgToolkit/Compactor/Table.pm line 496, <GEN8> line 6.
Thu Sep 11 08:01:44 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 2.052s, statement: 
ANALYZE partitions.history_p2014_07_28
Thu Sep 11 08:01:44 2014 zabbix, partitions.history_p2014_07_28 INFO Analyze final: duration 2.052 second.
Thu Sep 11 08:01:44 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.001s, statement: 
SELECT
    ceil(pure_page_count * 100 / fillfactor) AS effective_page_count,
    CASE WHEN size::real > 0 THEN
        round(
            100 * (
                1 - (pure_page_count * 100 / fillfactor) / (size::real / bs)
            )::numeric, 2
        )
    ELSE 0 END AS free_percent,
    ceil(size::real - bs * pure_page_count * 100 / fillfactor) AS free_space
FROM (
    SELECT
        bs, size, fillfactor,
        ceil(
            reltuples * (
                max(stanullfrac) * ma * ceil(
                    (
                        ma * ceil(
                            (
                                header_width +
                                ma * ceil(count(1)::real / ma)
                            )::real / ma
                        ) + sum((1 - stanullfrac) * stawidth)
                    )::real / ma
                ) +
                (1 - max(stanullfrac)) * ma * ceil(
                    (
                        ma * ceil(header_width::real / ma) +
                        sum((1 - stanullfrac) * stawidth)
                    )::real / ma
                )
            )::real / (bs - 24)
        ) AS pure_page_count
    FROM (
        SELECT
            pg_catalog.pg_class.oid AS class_oid,
            reltuples,
            23 AS header_width, 8 AS ma,
            current_setting('block_size')::integer AS bs,
            pg_catalog.pg_relation_size(pg_catalog.pg_class.oid) AS size,
            coalesce(
                (
                    SELECT (
                        regexp_matches(
                            reloptions::text, E'.*fillfactor=(\\d+).*'))[1]),
                '100')::real AS fillfactor
        FROM pg_catalog.pg_class
        WHERE pg_catalog.pg_class.oid = 'partitions.history_p2014_07_28'::regclass
    ) AS const
    LEFT JOIN pg_catalog.pg_statistic ON starelid = class_oid
    GROUP BY bs, class_oid, fillfactor, ma, size, reltuples, header_width
) AS sq

Thu Sep 11 08:01:44 2014 zabbix, partitions.history_p2014_07_28 WARNING Processing incomplete.
Thu Sep 11 08:01:44 2014 zabbix, partitions.history_p2014_07_28 NOTICE Processing results: 14771 pages left (23691 pages including toasts and indexes), size reduced by 0 bytes (0 bytes including toasts and indexes) in total, approximately 7.93% (1171 pages) that is 9368 kB more were expected to be compacted after this attempt.

[grayhemp]

Спасибо, буду копать.

On Thu, Sep 11, 2014 at 1:04 AM, Denis notifications@github.com wrote:

Thu Sep 11 08:01:40 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.001s, statement:
SELECT pg_try_advisory_lock(
'pg_catalog.pg_class'::regclass::integer,
'partitions.history_p2014_07_28'::regclass::integer)::integer;

Thu Sep 11 08:01:40 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.011s, statement:
SELECT
size,
total_size,
ceil(size::real / bs) AS page_count,
ceil(total_size::real / bs) AS total_page_count
FROM (
SELECT
current_setting('block_size')::integer AS bs,
pg_catalog.pg_relation_size('partitions.history_p2014_07_28') AS size,
pg_catalog.pg_total_relation_size('partitions.history_p2014_07_28') AS total_size
) AS sq

Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.922s, statement:
VACUUM partitions.history_p2014_07_28
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.002s, statement:
SELECT
size,
total_size,
ceil(size::real / bs) AS page_count,
ceil(total_size::real / bs) AS total_page_count
FROM (
SELECT
current_setting('block_size')::integer AS bs,
pg_catalog.pg_relation_size('partitions.history_p2014_07_28') AS size,
pg_catalog.pg_total_relation_size('partitions.history_p2014_07_28') AS total_size
) AS sq

Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 INFO Vacuum initial: 14771 pages left, duration 0.922 seconds.
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.019s, statement:
SELECT
ceil(pure_page_count * 100 / fillfactor) AS effective_page_count,
CASE WHEN size::real > 0 THEN
round(
100 * (
1 - (pure_page_count * 100 / fillfactor) / (size::real / bs)
)::numeric, 2
)
ELSE 0 END AS free_percent,
ceil(size::real - bs * pure_page_count * 100 / fillfactor) AS free_space
FROM (
SELECT
bs, size, fillfactor,
ceil(
reltuples * (
max(stanullfrac) * ma * ceil(
(
ma * ceil(
(
header_width +
ma * ceil(count(1)::real / ma)
)::real / ma
) + sum((1 - stanullfrac) * stawidth)
)::real / ma
) +
(1 - max(stanullfrac)) * ma * ceil(
(
ma * ceil(header_width::real / ma) +
sum((1 - stanullfrac) * stawidth)
)::real / ma
)
)::real / (bs - 24)
) AS pure_page_count
FROM (
SELECT
pg_catalog.pg_class.oid AS class_oid,
reltuples,
23 AS header_width, 8 AS ma,
current_setting('block_size')::integer AS bs,
pg_catalog.pg_relation_size(pg_catalog.pg_class.oid) AS size,
coalesce(
(
SELECT (
regexp_matches(
reloptions::text, E'.fillfactor=(\d+).'))[1]),
'100')::real AS fillfactor
FROM pg_catalog.pg_class
WHERE pg_catalog.pg_class.oid = 'partitions.history_p2014_07_28'::regclass
) AS const
LEFT JOIN pg_catalog.pg_statistic ON starelid = class_oid
GROUP BY bs, class_oid, fillfactor, ma, size, reltuples, header_width
) AS sq

Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 NOTICE Statistics: 14771 pages (23691 pages including toasts and indexes), approximately 7.99% (1180 pages) can be compacted reducing the size by 9440 kB.
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.001s, statement:
SELECT count(1) FROM pg_catalog.pg_trigger
WHERE
tgrelid = 'partitions.history_p2014_07_28'::regclass AND
tgenabled IN ('A', 'R') AND
(tgtype & 16)::boolean

Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.001s, statement:
SELECT attname
FROM pg_catalog.pg_attribute
WHERE
attnum > 0 AND -- neither system
NOT attisdropped AND -- nor dropped
attrelid = 'partitions.history_p2014_07_28'::regclass
ORDER BY
-- Variable legth attributes have lower priority because of the chance
-- of being toasted
(attlen = -1),
-- Preferably not indexed attributes
(
attnum::text IN (
SELECT regexp_split_to_table(indkey::text, ' ')
FROM pg_catalog.pg_index
WHERE indrelid = 'partitions.history_p2014_07_28'::regclass)),
-- Preferably smaller attributes
attlen,
attnum
LIMIT 1;

Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.001s, statement:
SELECT ceil(current_setting('block_size')::real / sum(attlen))
FROM pg_catalog.pg_attribute
WHERE
attrelid = 'partitions.history_p2014_07_28'::regclass AND
attnum < 0;

Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 INFO Update by column: ns.
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 INFO Set pages/round: 10.
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 INFO Set pages/vacuum: 924.
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG1 Executed SQL: duration 0.001s, statement:
BEGIN;
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG1 Executed SQL: duration 0.042s, statement:
SELECT public.pgcompact_clean_pages_7473(
'partitions.history_p2014_07_28', 'ns', 14770,
10, 316)

Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 WARNING Incorrect result of cleaning: column_ident ns, to_page 14770, pages_per_round 10, max_tupples_per_page 316.
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG1 Executed SQL: duration 0.001s, statement:
COMMIT;
Use of uninitialized value $to_page in subtraction (-) at /loader/0xc66ef0/PgToolkit/Compactor/Table.pm line 456, line 6.
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 INFO Cleaning in average: 236.8 pages/second (0.042 seconds per 10 pages).
Thu Sep 11 08:01:42 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.119s, statement:
VACUUM partitions.history_p2014_07_28
Thu Sep 11 08:01:42 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.001s, statement:
SELECT
size,
total_size,
ceil(size::real / bs) AS page_count,
ceil(total_size::real / bs) AS total_page_count
FROM (
SELECT
current_setting('block_size')::integer AS bs,
pg_catalog.pg_relation_size('partitions.history_p2014_07_28') AS size,
pg_catalog.pg_total_relation_size('partitions.history_p2014_07_28') AS total_size
) AS sq

Use of uninitialized value $arg_hash{"to_page"} in addition (+) at /loader/0xc66ef0/PgToolkit/Compactor/Table.pm line 855, line 6.
Use of uninitialized value $arg_hash{"to_page"} in addition (+) at /loader/0xc66ef0/PgToolkit/Compactor/Table.pm line 857, line 6.
Use of uninitialized value $arg_hash{"to_page"} in subtraction (-) at /loader/0xc66ef0/PgToolkit/Compactor/Table.pm line 865, line 6.
Thu Sep 11 08:01:42 2014 zabbix, partitions.history_p2014_07_28 NOTICE Vacuum routine: can not clean 14770 pages, 14771 pages left, duration 0.119 seconds.
Use of uninitialized value $to_page in numeric ge (>=) at /loader/0xc66ef0/PgToolkit/Compactor/Table.pm line 492, line 6.
Use of uninitialized value $to_page in numeric le (<=) at /loader/0xc66ef0/PgToolkit/Compactor/Table.pm line 496, line 6.
Thu Sep 11 08:01:44 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 2.052s, statement:
ANALYZE partitions.history_p2014_07_28
Thu Sep 11 08:01:44 2014 zabbix, partitions.history_p2014_07_28 INFO Analyze final: duration 2.052 second.
Thu Sep 11 08:01:44 2014 zabbix, partitions.history_p2014_07_28 DEBUG0 Executed SQL: duration 0.001s, statement:
SELECT
ceil(pure_page_count * 100 / fillfactor) AS effective_page_count,
CASE WHEN size::real > 0 THEN
round(
100 * (
1 - (pure_page_count * 100 / fillfactor) / (size::real / bs)
)::numeric, 2
)
ELSE 0 END AS free_percent,
ceil(size::real - bs * pure_page_count * 100 / fillfactor) AS free_space
FROM (
SELECT
bs, size, fillfactor,
ceil(
reltuples * (
max(stanullfrac) * ma * ceil(
(
ma * ceil(
(
header_width +
ma * ceil(count(1)::real / ma)
)::real / ma
) + sum((1 - stanullfrac) * stawidth)
)::real / ma
) +
(1 - max(stanullfrac)) * ma * ceil(
(
ma * ceil(header_width::real / ma) +
sum((1 - stanullfrac) * stawidth)
)::real / ma
)
)::real / (bs - 24)
) AS pure_page_count
FROM (
SELECT
pg_catalog.pg_class.oid AS class_oid,
reltuples,
23 AS header_width, 8 AS ma,
current_setting('block_size')::integer AS bs,
pg_catalog.pg_relation_size(pg_catalog.pg_class.oid) AS size,
coalesce(
(
SELECT (
regexp_matches(
reloptions::text, E'.fillfactor=(\d+).'))[1]),
'100')::real AS fillfactor
FROM pg_catalog.pg_class
WHERE pg_catalog.pg_class.oid = 'partitions.history_p2014_07_28'::regclass
) AS const
LEFT JOIN pg_catalog.pg_statistic ON starelid = class_oid
GROUP BY bs, class_oid, fillfactor, ma, size, reltuples, header_width
) AS sq

Thu Sep 11 08:01:44 2014 zabbix, partitions.history_p2014_07_28 WARNING Processing incomplete.
Thu Sep 11 08:01:44 2014 zabbix, partitions.history_p2014_07_28 NOTICE Processing results: 14771 pages left (23691 pages including toasts and indexes), size reduced by 0 bytes (0 bytes including toasts and indexes) in total, approximately 7.93% (1171 pages) that is 9368 kB more were expected to be compacted after this attempt.

—
Reply to this email directly or view it on GitHub
#3 (comment).

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@gmail.com

[grayhemp]

On Thu, Sep 11, 2014 at 1:04 AM, Denis notifications@github.com wrote:
[...]

Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG1 Executed SQL: duration 0.042s, statement:
SELECT public.pgcompact_clean_pages_7473(
'partitions.history_p2014_07_28', 'ns', 14770,
10, 316)

Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 WARNING Incorrect result of cleaning: column_ident ns, to_page 14770, pages_per_round 10, max_tupples_per_page 316.
Thu Sep 11 08:01:41 2014 zabbix, partitions.history_p2014_07_28 DEBUG1 Executed SQL: duration 0.001s, statement:
COMMIT;
Use of uninitialized value $to_page in subtraction (-) at /loader/0xc66ef0/PgToolkit/Compactor/Table.pm line 456, line 6.
[...]

I've been trying to reproduce the error for two days, and,
unfortunately, with no success. It looks even more strange for me
because, as I can see, the pgcompact_clean_pages_NNN() excludes any
ability of returning NULL. So, I assume that it could be an
underlining software problem, like DBI driver.

Could you please show what pgcompact chooses as a connection method?

It usually prints it in the beginning of the log if --verbosity is
"info" or higher.

Sun Sep 14 17:51:09 2014 INFO Database connection method: psql.

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@gmail.com

[grayhemp]

On Sun, Sep 14, 2014 at 6:21 PM, Sergey Konoplev gray.ru@gmail.com wrote:

I've been trying to reproduce the error for two days, and,
unfortunately, with no success. It looks even more strange for me
because, as I can see, the pgcompact_clean_pages_NNN() excludes any
ability of returning NULL. So, I assume that it could be an
underlining software problem, like DBI driver.

Test version, including the protection against the "incorrect result
of cleaning" error consequences it ready. It would be nice if you try
it on the system where the problem is reproducible.

https://github.com/grayhemp/pgtoolkit/tree/v1.0testing

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@gmail.com

[DenisBY]

Mon Sep 15 09:32:43 2014 INFO Database connection method: psql.

Mon Sep 15 09:45:26 2014 zabbix, partitions.history_p2014_07_28 INFO Vacuum initial: 14771 pages left, duration 0.926 seconds.
Mon Sep 15 09:45:26 2014 zabbix, partitions.history_p2014_07_28 NOTICE Statistics: 14771 pages (23691 pages including toasts and indexes), approximately 7.99% (1180 pages) can be compacted reducing the size by 9440 kB.
Mon Sep 15 09:45:26 2014 zabbix, partitions.history_p2014_07_28 INFO Update by column: ns.
Mon Sep 15 09:45:26 2014 zabbix, partitions.history_p2014_07_28 INFO Set pages/round: 10.
Mon Sep 15 09:45:26 2014 zabbix, partitions.history_p2014_07_28 INFO Set pages/vacuum: 924.
Mon Sep 15 09:45:26 2014 zabbix, partitions.history_p2014_07_28 WARNING Incorrect result of cleaning: column_ident ns, to_page 14770, pages_per_round 10, max_tupples_per_page 316.
Mon Sep 15 09:45:26 2014 zabbix, partitions.history_p2014_07_28 ERROR A database error occurred, exiting:
DatabaseError Can not executie command: 
 VACUUM partitions.history_p2014_07_28
 ERROR:  VACUUM cannot run inside a transaction block

I can create dump and upload it somewhere for your tests.

[grayhemp]

On Mon, Sep 15, 2014 at 3:12 AM, Denis notifications@github.com wrote:

Mon Sep 15 09:45:26 2014 zabbix, partitions.history_p2014_07_28 WARNING Incorrect result of cleaning: column_ident ns, to_page 14770, pages_per_round 10, max_tupples_per_page 316.
Mon Sep 15 09:45:26 2014 zabbix, partitions.history_p2014_07_28 ERROR A database error occurred, exiting:
DatabaseError Can not executie command:
VACUUM partitions.history_p2014_07_28
ERROR: VACUUM cannot run inside a transaction block

I have just updated v1.0testing, so try again please.

https://github.com/grayhemp/pgtoolkit/tree/v1.0testing

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@gmail.com