Re: pg15b3: crash in paralell vacuum

On Thu, Aug 18, 2022 at 11:06 PM Masahiko Sawada <sawada(dot)mshk(at)gmail(dot)com> wrote:
>
> Hi,
>
> On Thu, Aug 18, 2022 at 10:34 PM Justin Pryzby <pryzby(at)telsasoft(dot)com> wrote:
> >
> > Immediately after upgrading an internal instance, a loop around "vacuum" did
> > this:
>
> Thank you for the report!
>
> >
> > TRAP: FailedAssertion("indstats->status == PARALLEL_INDVAC_STATUS_INITIAL", File: "vacuumparallel.c", Line: 611, PID: 27635)
> > postgres: postgres pryzbyj [local] VACUUM(ExceptionalCondition+0x8d)[0x99d9fd]
> > postgres: postgres pryzbyj [local] VACUUM[0x6915db]
> > postgres: postgres pryzbyj [local] VACUUM(heap_vacuum_rel+0x12b6)[0x5083e6]
> > postgres: postgres pryzbyj [local] VACUUM[0x68e97a]
> > postgres: postgres pryzbyj [local] VACUUM(vacuum+0x48e)[0x68fe9e]
> > postgres: postgres pryzbyj [local] VACUUM(ExecVacuum+0x2ae)[0x69065e]
> > postgres: postgres pryzbyj [local] VACUUM(standard_ProcessUtility+0x530)[0x8567b0]
> > /usr/pgsql-15/lib/pg_stat_statements.so(+0x5450)[0x7f52b891c450]
> > postgres: postgres pryzbyj [local] VACUUM[0x85490a]
> > postgres: postgres pryzbyj [local] VACUUM[0x854a53]
> > postgres: postgres pryzbyj [local] VACUUM(PortalRun+0x179)[0x855029]
> > postgres: postgres pryzbyj [local] VACUUM[0x85099b]
> > postgres: postgres pryzbyj [local] VACUUM(PostgresMain+0x199a)[0x85268a]
> > postgres: postgres pryzbyj [local] VACUUM[0x496a21]
> > postgres: postgres pryzbyj [local] VACUUM(PostmasterMain+0x11c0)[0x7b3980]
> > postgres: postgres pryzbyj [local] VACUUM(main+0x1c6)[0x4986a6]
> > /lib64/libc.so.6(__libc_start_main+0xf5)[0x7f52c4b893d5]
> > postgres: postgres pryzbyj [local] VACUUM[0x498c59]
> > < 2022-08-18 07:56:51.963 CDT >LOG: server process (PID 27635) was terminated by signal 6: Aborted
> > < 2022-08-18 07:56:51.963 CDT >DETAIL: Failed process was running: VACUUM ANALYZE alarms
> >
> > Unfortunately, it looks like the RPM packages are compiled with -O2, so this is
> > of limited use.
> >
> > Core was generated by `postgres: postgres pryzbyj [local] VACUUM '.
> > Program terminated with signal 6, Aborted.
> > #0 0x00007f52c4b9d207 in raise () from /lib64/libc.so.6
> > Missing separate debuginfos, use: debuginfo-install audit-libs-2.8.4-4.el7.x86_64 bzip2-libs-1.0.6-13.el7.x86_64 cyrus-sasl-lib-2.1.26-23.el7.x86_64 elfutils-libelf-0.176-5.el7.x86_64 elfutils-libs-0.176-5.el7.x86_64 glibc-2.17-260.el7_6.3.x86_64 keyutils-libs-1.5.8-3.el7.x86_64 krb5-libs-1.15.1-51.el7_9.x86_64 libattr-2.4.46-13.el7.x86_64 libcap-2.22-9.el7.x86_64 libcap-ng-0.7.5-4.el7.x86_64 libcom_err-1.42.9-19.el7.x86_64 libgcc-4.8.5-39.el7.x86_64 libgcrypt-1.5.3-14.el7.x86_64 libgpg-error-1.12-3.el7.x86_64 libicu-50.1.2-17.el7.x86_64 libselinux-2.5-15.el7.x86_64 libstdc++-4.8.5-39.el7.x86_64 libxml2-2.9.1-6.el7_9.6.x86_64 libzstd-1.5.2-1.el7.x86_64 lz4-1.7.5-2.el7.x86_64 nspr-4.19.0-1.el7_5.x86_64 nss-3.36.0-7.1.el7_6.x86_64 nss-softokn-freebl-3.36.0-5.el7_5.x86_64 nss-util-3.36.0-1.1.el7_6.x86_64 openldap-2.4.44-21.el7_6.x86_64 openssl-libs-1.0.2k-22.el7_9.x86_64 pam-1.1.8-22.el7.x86_64 pcre-8.32-17.el7.x86_64 systemd-libs-219-62.el7_6.5.x86_64 xz-libs-5.2.2-1.el7.x86_64 zlib-1.2.7-18.el7.x86_64
> > (gdb) bt
> > #0 0x00007f52c4b9d207 in raise () from /lib64/libc.so.6
> > #1 0x00007f52c4b9e8f8 in abort () from /lib64/libc.so.6
> > #2 0x000000000099da1e in ExceptionalCondition (conditionName=conditionName(at)entry=0xafae40 "indstats->status == PARALLEL_INDVAC_STATUS_INITIAL", errorType=errorType(at)entry=0x9fb4b7 "FailedAssertion",
> > fileName=fileName(at)entry=0xafb0c0 "vacuumparallel.c", lineNumber=lineNumber(at)entry=611) at assert.c:69
> > #3 0x00000000006915db in parallel_vacuum_process_all_indexes (pvs=0x2e85f80, num_index_scans=<optimized out>, vacuum=<optimized out>) at vacuumparallel.c:611
> > #4 0x00000000005083e6 in heap_vacuum_rel (rel=<optimized out>, params=<optimized out>, bstrategy=<optimized out>) at vacuumlazy.c:2679
>
> It seems that parallel_vacuum_cleanup_all_indexes() got called[1],
> which means this was the first time to perform parallel vacuum (i.e.,
> index cleanup).

Sorry, this explanation is wrong. But according to the recent
information from Justin it was the first time to perform parallel
vacuum:

#3 0x00000000006874f1 in parallel_vacuum_process_all_indexes
(pvs=0x25bdce0, num_index_scans=0, vacuum=vacuum(at)entry=false) at
vacuumparallel.c:611
611 Assert(indstats->status ==
PARALLEL_INDVAC_STATUS_INITIAL);

Regards,

--
Masahiko Sawada
EDB: https://www.enterprisedb.com/