MIME-Version: 1.0
Content-Type: text/plain; charset=US-ASCII;
 format=flowed
Content-Transfer-Encoding: 7bit
Date: Thu, 11 Apr 2019 12:35:34 +0700
From: r.zharkov@postgrespro.ru
To: Thomas Munro <thomas.munro@gmail.com>
Cc: Michael Paquier <michael@paquier.xyz>, Andres Freund
 <andres@anarazel.de>, Tom Lane <tgl@sss.pgh.pa.us>, PostgreSQL mailing lists
 <pgsql-bugs@lists.postgresql.org>
Subject: Re: BUG #15727: PANIC: cannot abort transaction 295144144, it was
 already committed
In-Reply-To: 
 <CA+hUKG+NC+0767_b3vme6LhnkERLEU9SaCJGHoUJA1oeEv-=KA@mail.gmail.com>
References: <20190403122027.GA17929@alvherre.pgsql>
 <994bff111c549f45041cd1dc7473548e@postgrespro.ru>
 <19321.1554567786@sss.pgh.pa.us>
 <20190406162846.uohf5lcybz4ldrxh@alap3.anarazel.de>
 <199712fc251b6216f106edd07770d6c4@postgrespro.ru>
 <20190406171705.dogsasgftooz5rf5@alap3.anarazel.de>
 <17809a9ce6649f6b9095d782d73ed26b@postgrespro.ru>
 <20190411034730.GJ2728@paquier.xyz>
 <ACFBFD01-D22B-429D-946E-9F1CD68F2616@postgrespro.ru>
 <20190411042342.GP2728@paquier.xyz>
 <CA+hUKG+NC+0767_b3vme6LhnkERLEU9SaCJGHoUJA1oeEv-=KA@mail.gmail.com>
Message-ID: <4f774e94b0ec4942a265947efb493b35@postgrespro.ru>
User-Agent: Roundcube Webmail/1.3.8
Precedence: bulk

On 2019-04-11 11:44, Thomas Munro wrote:
>> Cool, thanks for confirming.
> 
> Thanks.  Looking into this.

Hi,
I think that the problem is in the autovacuum.

...
2019-04-11 08:04:49.593 MSK [24671] LOG:  automatic analyze of table 
"test.public.pgbench_accounts" system usage: CPU: user: 0.15 s, system: 
0.00 s, elapsed: 0.17 s
2019-04-11 08:05:29.137 MSK [13263] LOG:  checkpoint starting: wal
2019-04-11 08:05:49.352 MSK [25040] LOG:  automatic analyze of table 
"test.public.pgbench_accounts" system usage: CPU: user: 0.15 s, system: 
0.00 s, elapsed: 0.18 s
2019-04-11 08:06:49.449 MSK [25058] LOG:  automatic vacuum of table 
"test.public.pgbench_accounts": index scans: 1
         pages: 0 removed, 2145 remain, 1 skipped due to pins, 0 skipped 
frozen
         tuples: 8349 removed, 100975 remain, 976 are dead but not yet 
removable, oldest xmin: 195581926
         buffer usage: 6303 hits, 0 misses, 43 dirtied
         avg read rate: 0.000 MB/s, avg write rate: 1.353 MB/s
         system usage: CPU: user: 0.16 s, system: 0.00 s, elapsed: 0.24 s
2019-04-11 08:06:49.623 MSK [25058] LOG:  automatic analyze of table 
"test.public.pgbench_accounts" system usage: CPU: user: 0.13 s, system: 
0.01 s, elapsed: 0.17 s
2019-04-11 08:06:57.478 MSK [13263] LOG:  checkpoint complete: wrote 
2378 buffers (14.5%); 0 WAL file(s) added, 0 removed, 42 recycled; 
write=88.322 s, sync=0.000 s, total=88.340 s; sync fi
les=6, longest=0.000 s, average=0.000 s; distance=688127 kB, 
estimate=688128 kB
2019-04-11 08:07:49.451 MSK [25084] LOG:  automatic analyze of table 
"test.public.pgbench_accounts" system usage: CPU: user: 0.15 s, system: 
0.01 s, elapsed: 0.22 s
2019-04-11 08:08:28.963 MSK [13263] LOG:  checkpoint starting: wal
2019-04-11 08:08:49.500 MSK [25100] LOG:  automatic vacuum of table 
"test.public.pgbench_accounts": index scans: 1
         pages: 0 removed, 2145 remain, 1 skipped due to pins, 0 skipped 
frozen
         tuples: 8666 removed, 101047 remain, 1047 are dead but not yet 
removable, oldest xmin: 198748530
         buffer usage: 6243 hits, 0 misses, 15 dirtied
         avg read rate: 0.000 MB/s, avg write rate: 0.480 MB/s
         system usage: CPU: user: 0.17 s, system: 0.00 s, elapsed: 0.24 s
2019-04-11 08:08:49.678 MSK [25100] LOG:  automatic analyze of table 
"test.public.pgbench_accounts" system usage: CPU: user: 0.13 s, system: 
0.01 s, elapsed: 0.17 s
TRAP: FailedAssertion("!((((tuple->t_data->t_infomask) & 0x0080) || 
(((tuple->t_data->t_infomask) & (0x1000 | ((0x0040 | 0x0010) | 0x0040 | 
0x0010))) == 0x0040)))", File: "heapam.c", Line:
4289)
2019-04-11 08:09:37.452 MSK [13261] LOG:  server process (PID 13294) was 
terminated by signal 6: Aborted
2019-04-11 08:09:37.452 MSK [13261] DETAIL:  Failed process was running: 
UPDATE pgbench_accounts SET abalance = 1 WHERE aid = 2;

-- 
regards,

Roman Zharkov