AW: BUG #16045: vacuum_db crash and illegal memory alloc afterpg_upgrade from PG11 to PG12

Hi Tomas,

Nice that you could reproduce it.
This was just the way I followed.

For your Info, here are my no-standard config params:

                name                |         current_setting
------------------------------------+---------------------------------
 application_name                   | psql
 auto_explain.log_analyze           | on
 auto_explain.log_min_duration      | 0
 auto_explain.log_nested_statements | on
 client_encoding                    | WIN1252
 cluster_name                       | HB_DEV
 data_checksums                     | on
 DateStyle                          | ISO, DMY
 default_text_search_config         | pg_catalog.german
 dynamic_shared_memory_type         | windows
 effective_cache_size               | 8GB
 lc_collate                         | C
 lc_ctype                           | German_Germany.1252
 lc_messages                        | C
 lc_monetary                        | German_Germany.1252
 lc_numeric                         | German_Germany.1252
 lc_time                            | German_Germany.1252
 log_destination                    | stderr
 log_directory                      | N:/ZZ_log/pg_log_hbdev
 log_error_verbosity                | verbose
 log_file_mode                      | 0640
 log_line_prefix                    | WHB %a %t %i %e %2l:>
 log_statement                      | mod
 log_temp_files                     | 0
 log_timezone                       | CET
 logging_collector                  | on
 maintenance_work_mem               | 128MB
 max_connections                    | 100
 max_stack_depth                    | 2MB
 max_wal_size                       | 1GB
 min_wal_size                       | 80MB
 pg_stat_statements.max             | 5000
 pg_stat_statements.track           | all
 random_page_cost                   | 1
 search_path                        | public, archiv, ablage, admin
 server_encoding                    | UTF8
 server_version                     | 12.0
 shared_buffers                     | 1GB
 shared_preload_libraries           | auto_explain,pg_stat_statements
 temp_buffers                       | 32MB
 TimeZone                           | CET
 transaction_deferrable             | off
 transaction_isolation              | read committed
 transaction_read_only              | off
 update_process_title               | off
 wal_buffers                        | 16MB
 wal_segment_size                   | 16MB
 work_mem                           | 32MB
(48 rows)

Indeed, the database has UTF8 Encoding.

The Extended error-log (i have set auto_explain):



WHB psql 2019-10-09 15:45:03 CEST  XX000  7:> ERROR:  XX000: invalid memory alloc request size 18446744073709551613
WHB psql 2019-10-09 15:45:03 CEST  XX000  8:> LOCATION:  palloc,
d:\pginstaller_12.auto\postgres.windows-x64\src\backend\utils\mmgr\mcxt.c:934
WHB psql 2019-10-09 15:45:03 CEST  XX000  9:> STATEMENT:  select * from q_tbl_archiv;
WHB vacuumdb 2019-10-09 15:46:42 CEST  00000  1:> LOG:  00000: duration: 0.022 ms  plan:
    Query Text: SELECT pg_catalog.set_config('search_path', '', false);
    Result  (cost=0.00..0.01 rows=1 width=32) (actual time=0.014..0.015 rows=1 loops=1)
WHB vacuumdb 2019-10-09 15:46:42 CEST  00000  2:> LOCATION:  explain_ExecutorEnd,
d:\pginstaller_12.auto\postgres.windows-x64\contrib\auto_explain\auto_explain.c:415
WHB vacuumdb 2019-10-09 15:46:42 CEST  00000  3:> LOG:  00000: duration: 0.072 ms  plan:
    Query Text: SELECT datname FROM pg_database WHERE datallowconn ORDER BY 1;
    Sort  (cost=1.16..1.16 rows=1 width=64) (actual time=0.063..0.064 rows=14 loops=1)
      Sort Key: datname
      Sort Method: quicksort  Memory: 26kB
      ->  Seq Scan on pg_database  (cost=0.00..1.15 rows=1 width=64) (actual time=0.018..0.022 rows=14 loops=1)
            Filter: datallowconn
            Rows Removed by Filter: 1
WHB vacuumdb 2019-10-09 15:46:42 CEST  00000  4:> LOCATION:  explain_ExecutorEnd,
d:\pginstaller_12.auto\postgres.windows-x64\contrib\auto_explain\auto_explain.c:415
WHB vacuumdb 2019-10-09 15:46:43 CEST  00000  1:> LOG:  00000: duration: 0.027 ms  plan:
    Query Text: SELECT pg_catalog.set_config('search_path', '', false);
    Result  (cost=0.00..0.01 rows=1 width=32) (actual time=0.012..0.013 rows=1 loops=1)
WHB vacuumdb 2019-10-09 15:46:43 CEST  00000  2:> LOCATION:  explain_ExecutorEnd,
d:\pginstaller_12.auto\postgres.windows-x64\contrib\auto_explain\auto_explain.c:415
WHB vacuumdb 2019-10-09 15:46:43 CEST  00000  3:> LOG:  00000: duration: 1.036 ms  plan:
    Query Text: SELECT c.relname, ns.nspname FROM pg_catalog.pg_class c
     JOIN pg_catalog.pg_namespace ns ON c.relnamespace OPERATOR(pg_catalog.=) ns.oid
     LEFT JOIN pg_catalog.pg_class t ON c.reltoastrelid OPERATOR(pg_catalog.=) t.oid
     WHERE c.relkind OPERATOR(pg_catalog.=) ANY (array['r', 'm'])
     ORDER BY c.relpages DESC;
    Sort  (cost=56.56..56.59 rows=13 width=132) (actual time=0.843..0.854 rows=320 loops=1)
      Sort Key: c.relpages DESC
      Sort Method: quicksort  Memory: 110kB
      ->  Hash Join  (cost=1.23..56.32 rows=13 width=132) (actual time=0.082..0.649 rows=320 loops=1)
            Hash Cond: (c.relnamespace = ns.oid)
            ->  Seq Scan on pg_class c  (cost=0.00..55.05 rows=13 width=76) (actual time=0.034..0.545 rows=320 loops=1)
                  Filter: ((relkind)::text = ANY ('{r,m}'::text[]))
                  Rows Removed by Filter: 950
            ->  Hash  (cost=1.10..1.10 rows=10 width=68) (actual time=0.022..0.022 rows=10 loops=1)
                  Buckets: 1024  Batches: 1  Memory Usage: 9kB
                  ->  Seq Scan on pg_namespace ns  (cost=0.00..1.10 rows=10 width=68) (actual time=0.010..0.011 rows=10
loops=1)
WHB vacuumdb 2019-10-09 15:46:43 CEST  00000  4:> LOCATION:  explain_ExecutorEnd,
d:\pginstaller_12.auto\postgres.windows-x64\contrib\auto_explain\auto_explain.c:415
WHB vacuumdb 2019-10-09 15:46:43 CEST  00000  5:> LOG:  00000: duration: 0.011 ms  plan:
    Query Text: SELECT pg_catalog.set_config('search_path', '', false);
    Result  (cost=0.00..0.01 rows=1 width=32) (actual time=0.008..0.008 rows=1 loops=1)
WHB vacuumdb 2019-10-09 15:46:43 CEST  00000  6:> LOCATION:  explain_ExecutorEnd,
d:\pginstaller_12.auto\postgres.windows-x64\contrib\auto_explain\auto_explain.c:415
WHB  2019-10-09 15:47:01 CEST  00000 22:> LOG:  00000: server process (PID 4708) was terminated by exception 0xC0000005
WHB  2019-10-09 15:47:01 CEST  00000 23:> DETAIL:  Failed process was running: ANALYZE admin.q_tbl_archiv;
WHB  2019-10-09 15:47:01 CEST  00000 24:> HINT:  See C include file "ntstatus.h" for a description of the hexadecimal
value.
WHB  2019-10-09 15:47:01 CEST  00000 25:> LOCATION:  LogChildExit,
d:\pginstaller_12.auto\postgres.windows-x64\src\backend\postmaster\postmaster.c:3670
WHB  2019-10-09 15:47:01 CEST  00000 26:> LOG:  00000: terminating any other active server processes
WHB  2019-10-09 15:47:01 CEST  00000 27:> LOCATION:  HandleChildCrash,
d:\pginstaller_12.auto\postgres.windows-x64\src\backend\postmaster\postmaster.c:3400
WHB psql 2019-10-09 15:47:01 CEST  57P02 10:> WARNING:  57P02: terminating connection because of crash of another
serverprocess 
WHB psql 2019-10-09 15:47:01 CEST  57P02 11:> DETAIL:  The postmaster has commanded this server process to roll back
thecurrent transaction and exit, because another server process exited abnormally and possibly corrupted shared memory. 
WHB psql 2019-10-09 15:47:01 CEST  57P02 12:> HINT:  In a moment you should be able to reconnect to the database and
repeatyour command. 
WHB psql 2019-10-09 15:47:01 CEST  57P02 13:> LOCATION:  quickdie,
d:\pginstaller_12.auto\postgres.windows-x64\src\backend\tcop\postgres.c:2717
WHB  2019-10-09 15:47:02 CEST  57P02  3:> WARNING:  57P02: terminating connection because of crash of another server
process
WHB  2019-10-09 15:47:02 CEST  57P02  4:> DETAIL:  The postmaster has commanded this server process to roll back the
currenttransaction and exit, because another server process exited abnormally and possibly corrupted shared memory. 
WHB  2019-10-09 15:47:02 CEST  57P02  5:> HINT:  In a moment you should be able to reconnect to the database and repeat
yourcommand. 
WHB  2019-10-09 15:47:02 CEST  57P02  6:> LOCATION:  quickdie,
d:\pginstaller_12.auto\postgres.windows-x64\src\backend\tcop\postgres.c:2717
WHB  2019-10-09 15:47:02 CEST  00000 28:> LOG:  00000: all server processes terminated; reinitializing
WHB  2019-10-09 15:47:02 CEST  00000 29:> LOCATION:  PostmasterStateMachine,
d:\pginstaller_12.auto\postgres.windows-x64\src\backend\postmaster\postmaster.c:3912
WHB  2019-10-09 15:47:02 CEST  00000  1:> LOG:  00000: database system was interrupted; last known up at 2019-10-09
15:46:03CEST 
WHB  2019-10-09 15:47:02 CEST  00000  2:> LOCATION:  StartupXLOG,
d:\pginstaller_12.auto\postgres.windows-x64\src\backend\access\transam\xlog.c:6277


The table was imported successively by pg_dump/pg_restore from the previous versions into pg11.

This was the same what I did on the other machine (pg 11.5). On this test machine I could successfully Export the table
withpg_dump -t. 

On the erroneous PG12 Cluster I succeeded to recreate a similar  table with the original create table Statements: no
Errors.

Under PG12 upgraded, I tried to select only the first column (select table_name from q_tbl_archiv) and got erroneaus
results(shown first 2 entries): 

cpsdb=# select table_name from q_tbl_archiv;
                 table_name
---------------------------------------------
 \x11chemmat\x17chm_season
 !collectionsheet\x15cs_season

It seems that the length Bytes are present in the Output.

Hope this Information helps.

Hans Buschmann