On Sat, 19 Dec 2020 at 13:00, Craig Ringer <craig.rin...@enterprisedb.com> wrote:
> Hi all > > The attached patch set follows on from the discussion in [1] "Add LWLock > blocker(s) information" by adding the actual LWLock* and the numeric > tranche ID to each LWLock related TRACE_POSTGRESQL_foo tracepoint. > > I've attached a systemtap script that makes use of the information exported by the enhanced LWLock tracepoints. It offers something akin to dynamic -DLWLOCK_STATS with automatic statistical aggregation and some selective LWLOCK_DEBUG output. The script isn't super pretty. I didn't try to separate event-data collection from results output, and there's some duplication in places. But it gives you an idea what's possible when we report lock pointers and tranche IDs to tracepoints and add entry/exit tracepoints. Key features: * Collect statistical aggregates on lwlock hold and wait durations across all processes. Stats are grouped by lockmode (shared or exclusive) and by tranche name, as well as rollup stats across all tranches. * Report lock wait and hold durations for each process when that process exits. Again, reported by mode and tranche name. * For long lock waits, print the waiter pid and waiting pid, along with each process's backend type and application_name if known, the acquire mode, and the acquire function The output is intended to be human-readable, but it'd be quite simple to convert it into raw tsv-style output suitable for ingestion into statistical postprocessing or graphing tools. It should be fairly easy to break down the stats by acquire function if desired, so LWLockAcquire(), LWLockWaitForVar(), and LWLockAcquireOrWait() are reported separately. They're combined in the current output. Capturing the current query string is pretty simple if needed, but I didn't think it was likely to be especially useful. Sample output for a pg_regress run attached. Abridged version follows. Here the !!W!! lines are "waited a long time", the !!H!! lines are "held a long time". Then [pid]:MyBackendType tranche_name wait_time_us (wait_time) in wait_func (appliation_name) => [blocker_pid] (blocker_application_name) . If blocker pid wasn't identified it won't be reported - I know how to fix that and will do so soon. !!W!! [ 93030]:3 BufferContent 12993 (0m0.012993s) in lwlock__acquire__start (pg_regress/text) !!W!! [ 93036]:3 LockManager 14540 (0m0.014540s) in lwlock__acquire__start (pg_regress/float8) => [ 93045] (pg_regress/regproc) !!W!! [ 93035]:3 BufferContent 12608 (0m0.012608s) in lwlock__acquire__start (pg_regress/float4) => [ 93034] (pg_regress/oid) !!W!! [ 93036]:3 LockManager 10301 (0m0.010301s) in lwlock__acquire__start (pg_regress/float8) !!W!! [ 93043]:3 LockManager 10356 (0m0.010356s) in lwlock__acquire__start (pg_regress/pg_lsn) !!H!! [ 93033]:3 BufferContent 20579 (0m0.020579s) (pg_regress/int8) !!W!! [ 93027]:3 BufferContent 10766 (0m0.010766s) in lwlock__acquire__start (pg_regress/char) => [ 93037] (pg_regress/bit) !!W!! [ 93036]:3 OidGen 12876 (0m0.012876s) in lwlock__acquire__start (pg_regress/float8) ... Then the summary rollup at the end of the run. This can also be output periodically during the run. Abbreviated for highlights: wait locks: all procs tranche mode count total avg variance min max W LW_EXCLUSIVE (all) E 54185 14062734 259 1850265 1 44177 W LW_SHARED (all) S 3668 1116022 304 1527261 2 18642 held locks: all procs tranche mode count total avg variance min max H LW_EXCLUSIVE (all) E 10438060 153077259 14 37035 1 195043 H LW_SHARED (all) S 14199902 65466934 4 5318 1 44030 all procs by tranche tranche mode count total avg variance min max W tranche (all) S 3668 1116022 304 1527261 2 18642 W tranche (all) E 54185 14062734 259 1850265 1 44177 W tranche WALInsert E 9839 2393229 243 1180294 2 14209 W tranche BufferContent E 3012 1726543 573 3869409 2 28186 W tranche BufferContent S 1664 657855 395 2185694 2 18642 W tranche LockFastPath E 28314 6327801 223 1278053 1 26133 W tranche LockFastPath S 87 59401 682 3703217 19 9454 W tranche LockManager E 7223 2764392 382 2514863 2 44177 Hope this is interesting to someone.
$ /usr/local/systemtap/bin/stap -v -g --suppress-time-limits \
-G track_per_process=0 \
-G log_waits_longer_than_us=9000 \
-G log_holds_longer_than_us=20000 \
-G hide_wait_total_summary_lt_us=10000 \
-G hide_held_total_summary_lt_us=20000 \
-G hide_wait_total_pid_lt_us=1000 \
-G hide_held_total_pid_lt_us=5000 \
-G periodic_summary=0 \
lwlock_hold_durations.stp
/home/craig/projects/2Q/postgres/dev/lwlock-tracepoints/build/tmp_install/home/craig/pg/lwlock-tracepoints/bin/postgres
...
Pass 5: starting run.
!!W!! [ 93027]:3 LockManager 10273 (0m0.010273s) in
lwlock__acquire__start (pg_regress/char)
!!W!! [ 93041]:3 LockManager 9704 (0m0.009704s) in
lwlock__acquire__start (pg_regress/uuid)
!!W!! [ 93042]:3 LockManager 10594 (0m0.010594s) in
lwlock__acquire__start (pg_regress/rangetypes)
!!W!! [ 93038]:3 LockManager 9352 (0m0.009352s) in
lwlock__acquire__start (pg_regress/txid)
!!W!! [ 93040]:3 LockManager 11706 (0m0.011706s) in
lwlock__acquire__start (pg_regress/money)
!!W!! [ 93043]:3 LockManager 9283 (0m0.009283s) in
lwlock__acquire__start (pg_regress/pg_lsn)
!!W!! [ 93044]:3 LockManager 14403 (0m0.014403s) in
lwlock__acquire__start (pg_regress/enum)
!!W!! [ 93030]:3 BufferContent 12993 (0m0.012993s) in
lwlock__acquire__start (pg_regress/text)
!!W!! [ 93036]:3 LockManager 14540 (0m0.014540s) in
lwlock__acquire__start (pg_regress/float8) => [ 93045] (pg_regress/regproc)
!!W!! [ 93035]:3 BufferContent 12608 (0m0.012608s) in
lwlock__acquire__start (pg_regress/float4) => [ 93034] (pg_regress/oid)
!!W!! [ 93036]:3 LockManager 10301 (0m0.010301s) in
lwlock__acquire__start (pg_regress/float8)
!!W!! [ 93043]:3 LockManager 10356 (0m0.010356s) in
lwlock__acquire__start (pg_regress/pg_lsn)
!!H!! [ 93033]:3 BufferContent 20579 (0m0.020579s) (pg_regress/int8)
!!W!! [ 93027]:3 BufferContent 10766 (0m0.010766s) in
lwlock__acquire__start (pg_regress/char) => [ 93037] (pg_regress/bit)
!!W!! [ 93036]:3 OidGen 12876 (0m0.012876s) in
lwlock__acquire__start (pg_regress/float8)
!!W!! [ 93031]:3 BufferContent 9811 (0m0.009811s) in
lwlock__acquire__start (pg_regress/int2) => [ 93034] (pg_regress/oid)
!!W!! [ 93032]:3 BufferContent 10828 (0m0.010828s) in
lwlock__acquire__start (pg_regress/int4) => [ 93034] (pg_regress/oid)
!!W!! [ 93041]:3 BufferContent 10661 (0m0.010661s) in
lwlock__acquire__start (pg_regress/uuid) => [ 93029] (pg_regress/varchar)
!!W!! [ 93028]:3 BufferContent 11029 (0m0.011029s) in
lwlock__acquire__start (pg_regress/name) => [ 93034] (pg_regress/oid)
!!W!! [ 93034]:3 WALInsert 11159 (0m0.011159s) in
lwlock__acquire__start (pg_regress/oid) => [ 93029] (pg_regress/varchar)
!!W!! [ 93035]:3 BufferContent 10028 (0m0.010028s) in
lwlock__acquire__start (pg_regress/float4) => [ 93039] (pg_regress/numeric)
!!W!! [ 93037]:3 LockFastPath 12627 (0m0.012627s) in
lwlock__acquire__start (pg_regress/bit) => [ 93027] (pg_regress/char)
!!W!! [ 93038]:3 LockFastPath 9767 (0m0.009767s) in
lwlock__acquire__start (pg_regress/txid) => [ 93030] (pg_regress/text)
!!W!! [ 93033]:3 LockFastPath 17754 (0m0.017754s) in
lwlock__acquire__start (pg_regress/int8) => [ 93037] (pg_regress/bit)
!!W!! [ 93043]:3 BufferContent 9085 (0m0.009085s) in
lwlock__acquire__start (pg_regress/pg_lsn) => [ 93040] (pg_regress/money)
!!H!! [ 93037]:3 LockFastPath 21646 (0m0.021646s) (pg_regress/bit)
!!W!! [ 93038]:3 BufferContent 12224 (0m0.012224s) in
lwlock__acquire__start (pg_regress/txid)
!!W!! [ 93026]:3 BufferContent 18506 (0m0.018506s) in
lwlock__acquire__start (pg_regress/boolean) => [ 93043] (pg_regress/pg_lsn)
!!W!! [ 93043]:3 BufferContent 10279 (0m0.010279s) in
lwlock__acquire__start (pg_regress/pg_lsn) => [ 93037] (pg_regress/bit)
!!W!! [ 93039]:3 LockFastPath 9423 (0m0.009423s) in
lwlock__acquire__start (pg_regress/numeric) => [ 93037] (pg_regress/bit)
!!W!! [ 93026]:3 LockFastPath 9101 (0m0.009101s) in
lwlock__acquire__start (pg_regress/boolean) => [ 93037] (pg_regress/bit)
!!W!! [ 93122]:3 LockManager 11423 (0m0.011423s) in
lwlock__acquire__start (backend)
!!W!! [ 93124]:3 LockManager 10483 (0m0.010483s) in
lwlock__acquire__start (backend)
!!W!! [ 93120]:3 LockManager 9656 (0m0.009656s) in
lwlock__acquire__start (backend)
!!W!! [ 93128]:3 LockManager 10185 (0m0.010185s) in
lwlock__acquire__start (backend)
!!W!! [ 93117]:3 LockManager 10076 (0m0.010076s) in
lwlock__acquire__start (backend)
!!W!! [ 93129]:3 LockManager 9752 (0m0.009752s) in
lwlock__acquire__start (backend)
!!W!! [ 93123]:3 LockManager 10074 (0m0.010074s) in
lwlock__acquire__start (backend)
!!W!! [ 93121]:3 LockManager 10964 (0m0.010964s) in
lwlock__acquire__start (backend)
!!W!! [ 93130]:3 LockManager 12478 (0m0.012478s) in
lwlock__acquire__start (pg_regress/tstypes)
!!W!! [ 93127]:3 LockManager 17921 (0m0.017921s) in
lwlock__acquire__start (pg_regress/inet)
!!W!! [ 93125]:3 LockManager 12108 (0m0.012108s) in
lwlock__acquire__start (pg_regress/timestamptz)
!!W!! [ 93114]:3 LockManager 12529 (0m0.012529s) in
lwlock__acquire__start (pg_regress/point)
!!W!! [ 93123]:3 LockManager 19230 (0m0.019230s) in
lwlock__acquire__start (backend)
!!W!! [ 93131]:3 LockManager 12313 (0m0.012313s) in
lwlock__acquire__start (pg_regress/xid)
!!W!! [ 93121]:3 LockManager 17151 (0m0.017151s) in
lwlock__acquire__start (pg_regress/date) => [ 93129] (pg_regress/macaddr8)
!!W!! [ 93122]:3 LockManager 20237 (0m0.020237s) in
lwlock__acquire__start (pg_regress/time) => [ 93129] (pg_regress/macaddr8)
!!W!! [ 93120]:3 LockManager 12522 (0m0.012522s) in
lwlock__acquire__start (pg_regress/circle)
!!W!! [ 93117]:3 BufferContent 10455 (0m0.010455s) in
lwlock__acquire__start (pg_regress/box) => [ 93114] (pg_regress/point)
!!W!! [ 93127]:3 BufferContent 12687 (0m0.012687s) in
lwlock__acquire__start (pg_regress/inet)
!!H!! [ 93114]:3 LockFastPath 21562 (0m0.021562s)
(pg_regress/point)
!!W!! [ 93116]:3 LockManager 11844 (0m0.011844s) in
lwlock__acquire__start (pg_regress/line)
!!W!! [ 93118]:3 LockFastPath 12301 (0m0.012301s) in
lwlock__acquire__start (pg_regress/polygon)
!!W!! [ 93129]:3 LockFastPath 9244 (0m0.009244s) in
lwlock__acquire__start (pg_regress/macaddr8)
!!W!! [ 93114]:3 BufferContent 10825 (0m0.010825s) in
lwlock__acquire__start (pg_regress/point)
!!W!! [ 93127]:3 BufferContent 10299 (0m0.010299s) in
lwlock__acquire__start (pg_regress/inet) => [ 93129] (pg_regress/macaddr8)
!!W!! [ 93120]:3 BufferContent 9897 (0m0.009897s) in
lwlock__acquire__start (pg_regress/circle) => [ 93118] (pg_regress/polygon)
!!W!! [ 93118]:3 BufferContent 11797 (0m0.011797s) in
lwlock__acquire__start (pg_regress/polygon)
!!W!! [ 93114]:3 BufferContent 9910 (0m0.009910s) in
lwlock__acquire__start (pg_regress/point) => [ 93120] (pg_regress/circle)
!!W!! [ 93118]:3 LockFastPath 10592 (0m0.010592s) in
lwlock__acquire__start (pg_regress/polygon) => [ 93115] (pg_regress/lseg)
!!W!! [ 93118]:3 LockFastPath 9330 (0m0.009330s) in
lwlock__acquire__start (pg_regress/polygon) => [ 93117] (pg_regress/box)
!!W!! [ 93123]:3 XidGen 12288 (0m0.012288s) in
lwlock__acquire__start (pg_regress/timetz)
!!W!! [ 93334]:3 LockFastPath 9462 (0m0.009462s) in
lwlock__acquire__start (pg_regress/errors) => [ 93330]
(pg_regress/updatable_views)
!!W!! [ 93327]:3 LockFastPath 10208 (0m0.010208s) in
lwlock__acquire__start (pg_regress/vacuum)
!!W!! [ 93321]:3 BufferContent 11945 (0m0.011945s) in
lwlock__acquire__start (pg_regress/constraints)
!!W!! [ 93323]:3 WALInsert 12017 (0m0.012017s) in
lwlock__waitforvar__start (pg_regress/create_cast) => [ 93327]
(pg_regress/vacuum)
!!W!! [ 93320]:3 LockFastPath 11787 (0m0.011787s) in
lwlock__acquire__start (pg_regress/create_function_3)
!!W!! [ 93328]:3 CheckpointerComm 10109 (0m0.010109s) in
lwlock__acquire__start (pg_regress/drop_if_exists)
!!W!! [ 93328]:3 LockFastPath 14180 (0m0.014180s) in
lwlock__acquire__start (pg_regress/drop_if_exists) => [ 93321]
(pg_regress/constraints)
!!W!! [ 93429]:3 LockManager 9486 (0m0.009486s) in
lwlock__acquire__start (backend)
!!W!! [ 93422]:3 LockManager 9645 (0m0.009645s) in
lwlock__acquire__start (backend)
!!W!! [ 93430]:3 LockManager 11516 (0m0.011516s) in
lwlock__acquire__start (backend)
!!H!! [ 93422]:3 BufferContent 21277 (0m0.021277s) (backend)
!!H!! [ 93430]:3 BufferMapping 24757 (0m0.024757s) (backend)
!!W!! [ 93418]:3 LockManager 9543 (0m0.009543s) in
lwlock__acquire__start (backend)
!!W!! [ 93420]:3 LockManager 11501 (0m0.011501s) in
lwlock__acquire__start (backend)
!!W!! [ 93430]:3 LockManager 12822 (0m0.012822s) in
lwlock__acquire__start (backend) => [ 93428] (backend)
!!W!! [ 93416]:3 LockManager 13507 (0m0.013507s) in
lwlock__acquire__start (backend)
!!W!! [ 93423]:3 LockManager 22805 (0m0.022805s) in
lwlock__acquire__start (backend)
!!W!! [ 93418]:3 LockManager 26451 (0m0.026451s) in
lwlock__acquire__start (backend)
!!W!! [ 93416]:3 LockManager 19325 (0m0.019325s) in
lwlock__acquire__start (backend)
!!H!! [ 93428]:3 LockFastPath 21848 (0m0.021848s) (backend)
!!W!! [ 93421]:3 LockManager 24576 (0m0.024576s) in
lwlock__acquire__start (backend)
!!W!! [ 93424]:3 LockManager 44177 (0m0.044177s) in
lwlock__acquire__start (backend)
!!H!! [ 93416]:3 BufferContent 44030 (0m0.044030s) (backend)
!!H!! [ 93424]:3 BufferContent 24081 (0m0.024081s) (backend)
!!H!! [ 93415]:3 LockFastPath 20074 (0m0.020074s) (backend)
!!W!! [ 93429]:3 LockManager 12798 (0m0.012798s) in
lwlock__acquire__start (backend) => [ 93432] (backend)
!!W!! [ 93426]:3 LockManager 10183 (0m0.010183s) in
lwlock__acquire__start (backend) => [ 93432] (backend)
!!W!! [ 93413]:3 LockManager 12550 (0m0.012550s) in
lwlock__acquire__start (backend) => [ 93432] (backend)
!!H!! [ 93415]:3 BufferMapping 26939 (0m0.026939s) (backend)
!!H!! [ 93416]:3 BufferMapping 20050 (0m0.020050s) (backend)
!!W!! [ 93420]:3 LockManager 12222 (0m0.012222s) in
lwlock__acquire__start (backend)
!!H!! [ 93423]:3 LockFastPath 24015 (0m0.024015s) (backend)
!!W!! [ 93430]:3 LockManager 12790 (0m0.012790s) in
lwlock__acquire__start (backend)
!!W!! [ 93421]:3 LockFastPath 12957 (0m0.012957s) in
lwlock__acquire__start (backend)
!!W!! [ 93425]:3 LockFastPath 11391 (0m0.011391s) in
lwlock__acquire__start (pg_regress/arrays) => [ 93417] (pg_regress/subselect)
!!W!! [ 93420]:3 LockManager 16605 (0m0.016605s) in
lwlock__acquire__start (backend)
!!W!! [ 93432]:3 LockFastPath 9996 (0m0.009996s) in
lwlock__acquire__start (pg_regress/prepared_xacts)
!!W!! [ 93422]:3 LockFastPath 12246 (0m0.012246s) in
lwlock__acquire__start (backend)
!!W!! [ 93425]:3 LockFastPath 11399 (0m0.011399s) in
lwlock__acquire__start (pg_regress/arrays) => [ 93420] (backend)
!!W!! [ 93427]:3 BufferContent 12836 (0m0.012836s) in
lwlock__acquire__start (pg_regress/delete) => [ 93429] (pg_regress/namespace)
!!W!! [ 93429]:3 LockFastPath 10783 (0m0.010783s) in
lwlock__acquire__start (pg_regress/namespace)
!!W!! [ 93417]:3 LockFastPath 11539 (0m0.011539s) in
lwlock__acquire__start (pg_regress/subselect)
!!W!! [ 93417]:3 WALInsert 11782 (0m0.011782s) in
lwlock__waitforvar__start (pg_regress/subselect)
!!W!! [ 93425]:3 BufferContent 12144 (0m0.012144s) in
lwlock__acquire__start (pg_regress/arrays) => [ 93427] (pg_regress/delete)
!!H!! [ 93420]:3 BufferMapping 20011 (0m0.020011s) (backend)
!!W!! [ 93424]:3 LockFastPath 15676 (0m0.015676s) in
lwlock__acquire__start (backend)
!!W!! [ 93415]:3 SInvalRead 10329 (0m0.010329s) in
lwlock__acquire__start (pg_regress/select_implicit)
!!W!! [ 93418]:3 ProcArray 11349 (0m0.011349s) in
lwlock__acquire__start (pg_regress/case) => [ 93425] (pg_regress/arrays)
!!W!! [ 93431]:3 LockFastPath 11625 (0m0.011625s) in
lwlock__acquire__start (backend)
!!W!! [ 93419]:3 ProcArray 13289 (0m0.013289s) in
lwlock__acquire__start (pg_regress/union)
!!W!! [ 93417]:3 LockFastPath 12145 (0m0.012145s) in
lwlock__acquire__start (pg_regress/subselect)
!!W!! [ 93429]:3 LockFastPath 12524 (0m0.012524s) in
lwlock__acquire__start (pg_regress/namespace) => [ 93426]
(pg_regress/hash_index)
!!W!! [ 93418]:3 LockFastPath 11292 (0m0.011292s) in
lwlock__acquire__start (pg_regress/case)
!!W!! [ 93430]:3 LockFastPath 13273 (0m0.013273s) in
lwlock__acquire__start (pg_regress/update)
!!W!! [ 93418]:3 XactSLRU 9765 (0m0.009765s) in
lwlock__acquire__start (pg_regress/case) => [ 93415]
(pg_regress/select_implicit)
!!W!! [ 93414]:3 BufferContent 9609 (0m0.009609s) in
lwlock__acquire__start (pg_regress/select_distinct)
!!W!! [ 93430]:3 BufferContent 9679 (0m0.009679s) in
lwlock__acquire__start (pg_regress/update) => [ 93427] (pg_regress/delete)
!!W!! [ 93416]:3 LockFastPath 12975 (0m0.012975s) in
lwlock__acquire__start (pg_regress/select_having)
!!W!! [ 93418]:3 WALInsert 12630 (0m0.012630s) in
lwlock__waitforvar__start (pg_regress/case)
!!W!! [ 93429]:3 LockFastPath 11233 (0m0.011233s) in
lwlock__acquire__start (pg_regress/namespace)
!!W!! [ 93416]:3 WALInsert 10615 (0m0.010615s) in
lwlock__waitforvar__start (pg_regress/select_having)
!!W!! [ 93423]:3 LockFastPath 11744 (0m0.011744s) in
lwlock__acquire__start (pg_regress/random) => [ 93422] (pg_regress/transactions)
!!W!! [ 93422]:3 WALInsert 9670 (0m0.009670s) in
lwlock__waitforvar__start (pg_regress/transactions)
!!W!! [ 93423]:3 WALInsert 12287 (0m0.012287s) in
lwlock__waitforvar__start (pg_regress/random)
!!W!! [ 93420]:3 WALInsert 12704 (0m0.012704s) in
lwlock__acquire__start (pg_regress/join)
!!W!! [ 93418]:3 LockFastPath 13090 (0m0.013090s) in
lwlock__acquire__start (pg_regress/case)
!!W!! [ 93415]:3 LockFastPath 19870 (0m0.019870s) in
lwlock__acquire__start (pg_regress/select_implicit) => [ 93424]
(pg_regress/select_into)
!!W!! [ 93422]:3 WALInsert 12761 (0m0.012761s) in
lwlock__acquire__start (pg_regress/transactions) => [ 93425] (pg_regress/arrays)
!!W!! [ 93420]:3 LockFastPath 9880 (0m0.009880s) in
lwlock__acquire__start (pg_regress/join) => [ 93429] (pg_regress/namespace)
!!W!! [ 93432]:3 LockFastPath 11430 (0m0.011430s) in
lwlock__acquire__start (pg_regress/prepared_xacts)
!!W!! [ 93425]:3 LockFastPath 9663 (0m0.009663s) in
lwlock__acquire__start (pg_regress/arrays)
!!W!! [ 93432]:3 BufferContent 11676 (0m0.011676s) in
lwlock__acquire__start (pg_regress/prepared_xacts) => [ 93425]
(pg_regress/arrays)
!!W!! [ 93427]:3 LockFastPath 13686 (0m0.013686s) in
lwlock__acquire__start (pg_regress/delete) => [ 93426] (pg_regress/hash_index)
!!W!! [ 93420]:3 ProcArray 10469 (0m0.010469s) in
lwlock__acquire__start (pg_regress/join) => [ 93418] (pg_regress/case)
!!W!! [ 93427]:3 LockFastPath 12492 (0m0.012492s) in
lwlock__acquire__start (pg_regress/delete)
!!W!! [ 93425]:3 ProcArray 14862 (0m0.014862s) in
lwlock__acquire__start (pg_regress/arrays)
!!W!! [ 93427]:3 ProcArray 9624 (0m0.009624s) in
lwlock__acquire__start (pg_regress/delete)
!!W!! [ 93417]:3 BufferContent 13209 (0m0.013209s) in
lwlock__acquire__start (pg_regress/subselect) => [ 93424]
(pg_regress/select_into)
!!W!! [ 93429]:3 LockFastPath 11449 (0m0.011449s) in
lwlock__acquire__start (pg_regress/namespace)
!!W!! [ 93415]:3 LockFastPath 12705 (0m0.012705s) in
lwlock__acquire__start (pg_regress/select_implicit) => [ 93419]
(pg_regress/union)
!!W!! [ 93427]:3 LockFastPath 26133 (0m0.026133s) in
lwlock__acquire__start (pg_regress/delete) => [ 93419] (pg_regress/union)
!!H!! [ 93431]:3 BufferContent 22761 (0m0.022761s)
(pg_regress/btree_index)
!!H!! [ 93431]:3 BufferContent 25676 (0m0.025676s)
(pg_regress/btree_index)
!!H!! [ 93431]:3 BufferContent 24783 (0m0.024783s)
(pg_regress/btree_index)
!!H!! [ 93431]:3 BufferContent 23317 (0m0.023317s)
(pg_regress/btree_index)
!!H!! [ 93431]:3 BufferContent 25128 (0m0.025128s)
(pg_regress/btree_index)
!!H!! [ 93431]:3 BufferContent 24428 (0m0.024428s)
(pg_regress/btree_index)
!!H!! [ 93431]:3 BufferContent 24897 (0m0.024897s)
(pg_regress/btree_index)
!!H!! [ 93431]:3 BufferContent 23688 (0m0.023688s)
(pg_regress/btree_index)
!!H!! [ 93431]:3 BufferContent 20458 (0m0.020458s)
(pg_regress/btree_index)
!!H!! [ 93431]:3 BufferContent 20114 (0m0.020114s)
(pg_regress/btree_index)
!!W!! [ 93554]:3 LockManager 13382 (0m0.013382s) in
lwlock__acquire__start (backend)
!!W!! [ 93543]:3 LockManager 12557 (0m0.012557s) in
lwlock__acquire__start (backend)
!!W!! [ 93557]:3 LockManager 13436 (0m0.013436s) in
lwlock__acquire__start (backend)
!!W!! [ 93551]:3 LockManager 15057 (0m0.015057s) in
lwlock__acquire__start (pg_regress/replica_identity)
!!W!! [ 93553]:3 LockManager 16350 (0m0.016350s) in
lwlock__acquire__start (pg_regress/object_address)
!!W!! [ 93552]:3 LockManager 17367 (0m0.017367s) in
lwlock__acquire__start (pg_regress/rowsecurity)
!!W!! [ 93555]:3 LockManager 11984 (0m0.011984s) in
lwlock__acquire__start (pg_regress/identity)
!!W!! [ 93550]:3 LockManager 12043 (0m0.012043s) in
lwlock__acquire__start (pg_regress/lock)
!!H!! [ 93560]:3 BufferMapping 20251 (0m0.020251s)
(pg_regress/groupingsets)
!!W!! [ 93558]:3 LockManager 12305 (0m0.012305s) in
lwlock__acquire__start (pg_regress/join_hash)
!!W!! [ 93553]:3 ProcArray 9702 (0m0.009702s) in
lwlock__acquire__start (pg_regress/object_address)
!!H!! [ 93555]:3 BufferMapping 20952 (0m0.020952s)
(pg_regress/identity)
!!W!! [ 93547]:3 BufferContent 13224 (0m0.013224s) in
lwlock__acquire__start (pg_regress/security_label) => [ 93548]
(pg_regress/collate)
!!H!! [ 93557]:3 LockFastPath 21874 (0m0.021874s)
(pg_regress/generated)
!!W!! [ 93552]:3 WALInsert 9574 (0m0.009574s) in
lwlock__waitforvar__start (pg_regress/rowsecurity) => [ 93553]
(pg_regress/object_address)
!!W!! [ 93551]:3 LockFastPath 14498 (0m0.014498s) in
lwlock__acquire__start (pg_regress/replica_identity) => [ 93539]
(pg_regress/gist)
!!W!! [ 93543]:3 BufferContent 9715 (0m0.009715s) in
lwlock__acquire__start (pg_regress/spgist) => [ 93546] (pg_regress/brin)
!!W!! [ 93541]:3 LockFastPath 10376 (0m0.010376s) in
lwlock__acquire__start (pg_regress/gin) => [ 93539] (pg_regress/gist)
!!W!! [ 93549]:3 BufferContent 12326 (0m0.012326s) in
lwlock__acquire__start (pg_regress/matview) => [ 93546] (pg_regress/brin)
!!W!! [ 93547]:3 LockFastPath 9371 (0m0.009371s) in
lwlock__acquire__start (pg_regress/security_label)
!!W!! [ 93543]:3 LockFastPath 12753 (0m0.012753s) in
lwlock__acquire__start (pg_regress/spgist) => [ 93553]
(pg_regress/object_address)
!!W!! [ 93557]:3 BufferContent 10364 (0m0.010364s) in
lwlock__acquire__start (pg_regress/generated) => [ 93555] (pg_regress/identity)
!!W!! [ 93544]:3 LockManager 9624 (0m0.009624s) in
lwlock__acquire__start (pg_regress/privileges)
!!W!! [ 93551]:3 BufferContent 13168 (0m0.013168s) in
lwlock__acquire__start (pg_regress/replica_identity)
!!W!! [ 93548]:3 BufferContent 20553 (0m0.020553s) in
lwlock__acquire__start (pg_regress/collate)
!!W!! [ 93558]:3 BufferContent 14277 (0m0.014277s) in
lwlock__acquire__start (pg_regress/join_hash) => [ 93560]
(pg_regress/groupingsets)
!!W!! [ 93547]:3 BufferContent 28186 (0m0.028186s) in
lwlock__acquire__start (pg_regress/security_label) => [ 93551]
(pg_regress/replica_identity)
!!W!! [ 93549]:3 BufferContent 18642 (0m0.018642s) in
lwlock__acquire__start (pg_regress/matview)
!!W!! [ 93547]:3 BufferContent 9148 (0m0.009148s) in
lwlock__acquire__start (pg_regress/security_label)
!!W!! [ 93560]:3 BufferContent 9399 (0m0.009399s) in
lwlock__acquire__start (pg_regress/groupingsets)
!!W!! [ 93543]:3 LockFastPath 9876 (0m0.009876s) in
lwlock__acquire__start (pg_regress/spgist)
!!W!! [ 93553]:3 LockFastPath 13232 (0m0.013232s) in
lwlock__acquire__start (pg_regress/object_address)
!!W!! [ 93558]:3 LockFastPath 9003 (0m0.009003s) in
lwlock__acquire__start (pg_regress/join_hash)
!!W!! [ 93558]:3 BufferContent 12445 (0m0.012445s) in
lwlock__acquire__start (pg_regress/join_hash) => [ 93552]
(pg_regress/rowsecurity)
!!W!! [ 93554]:3 WALInsert 10818 (0m0.010818s) in
lwlock__waitforvar__start (pg_regress/tablesample)
!!W!! [ 93550]:3 WALWrite 12831 (0m0.012831s) in
(pg_regress/lock) => [ 93559] (pg_regress/password)
!!W!! [ 93558]:3 LockFastPath 13317 (0m0.013317s) in
lwlock__acquire__start (pg_regress/join_hash)
!!W!! [ 93553]:3 LockFastPath 9331 (0m0.009331s) in
lwlock__acquire__start (pg_regress/object_address)
!!W!! [ 93555]:3 LockFastPath 10443 (0m0.010443s) in
lwlock__acquire__start (pg_regress/identity) => [ 93558] (pg_regress/join_hash)
!!W!! [ 93560]:3 BufferContent 9049 (0m0.009049s) in
lwlock__acquire__start (pg_regress/groupingsets) => [ 93544]
(pg_regress/privileges)
!!W!! [ 93539]:3 LockFastPath 9815 (0m0.009815s) in
lwlock__acquire__start (pg_regress/gist) => [ 93558] (pg_regress/join_hash)
!!W!! [ 93539]:3 LockFastPath 10885 (0m0.010885s) in
lwlock__acquire__start (pg_regress/gist) => [ 93557] (pg_regress/generated)
!!W!! [ 93551]:3 LockFastPath 10024 (0m0.010024s) in
lwlock__acquire__start (pg_regress/replica_identity) => [ 93557]
(pg_regress/generated)
!!W!! [ 93547]:3 BufferContent 13219 (0m0.013219s) in
lwlock__acquire__start (pg_regress/security_label) => [ 93541] (pg_regress/gin)
!!W!! [ 93552]:3 LockFastPath 11930 (0m0.011930s) in
lwlock__acquire__start (pg_regress/rowsecurity)
!!W!! [ 93551]:3 BufferContent 9593 (0m0.009593s) in
lwlock__acquire__start (pg_regress/replica_identity) => [ 93553]
(pg_regress/object_address)
!!W!! [ 93539]:3 LockFastPath 9683 (0m0.009683s) in
lwlock__acquire__start (pg_regress/gist)
!!W!! [ 93553]:3 LockFastPath 9720 (0m0.009720s) in
lwlock__acquire__start (pg_regress/object_address)
!!W!! [ 93544]:3 LockFastPath 13201 (0m0.013201s) in
lwlock__acquire__start (pg_regress/privileges)
!!W!! [ 93544]:3 LockFastPath 9081 (0m0.009081s) in
lwlock__acquire__start (pg_regress/privileges) => [ 93552]
(pg_regress/rowsecurity)
!!W!! [ 93550]:3 LockFastPath 12427 (0m0.012427s) in
lwlock__acquire__start (pg_regress/lock) => [ 93552] (pg_regress/rowsecurity)
!!W!! [ 93554]:3 LockFastPath 11323 (0m0.011323s) in
lwlock__acquire__start (pg_regress/tablesample) => [ 93561] (parallel worker)
!!W!! [ 93539]:3 LockFastPath 9259 (0m0.009259s) in
lwlock__acquire__start (pg_regress/gist)
!!H!! [ 93547]:3 BufferMapping 23928 (0m0.023928s)
(pg_regress/security_label)
!!H!! [ 93554]:3 BufferContent 20764 (0m0.020764s)
(pg_regress/tablesample)
!!W!! [ 93557]:3 BufferContent 10618 (0m0.010618s) in
lwlock__acquire__start (pg_regress/generated) => [ 93555] (pg_regress/identity)
!!W!! [ 93550]:3 BufferContent 13869 (0m0.013869s) in
lwlock__acquire__start (pg_regress/lock) => [ 93552] (pg_regress/rowsecurity)
!!W!! [ 93547]:3 BufferContent 11870 (0m0.011870s) in
lwlock__acquire__start (pg_regress/security_label) => [ 93557]
(pg_regress/generated)
!!W!! [ 93555]:3 BufferContent 11937 (0m0.011937s) in
lwlock__acquire__start (pg_regress/identity) => [ 93552]
(pg_regress/rowsecurity)
!!W!! [ 93548]:3 LockManager 11589 (0m0.011589s) in
lwlock__acquire__start (pg_regress/collate)
!!W!! [ 93553]:3 LockFastPath 11124 (0m0.011124s) in
lwlock__acquire__start (pg_regress/object_address) => [ 93552]
(pg_regress/rowsecurity)
!!W!! [ 93557]:3 LockFastPath 9782 (0m0.009782s) in
lwlock__acquire__start (pg_regress/generated) => [ 93550] (pg_regress/lock)
!!W!! [ 93541]:3 BufferMapping 13056 (0m0.013056s) in
lwlock__acquire__start (pg_regress/gin)
!!W!! [ 93539]:3 LockFastPath 9637 (0m0.009637s) in
lwlock__acquire__start (pg_regress/gist)
!!W!! [ 93557]:3 WALInsert 11415 (0m0.011415s) in
lwlock__acquire__start (pg_regress/generated)
!!W!! [ 93553]:3 BufferContent 10676 (0m0.010676s) in
lwlock__acquire__start (pg_regress/object_address) => [ 93557]
(pg_regress/generated)
!!W!! [ 93551]:3 BufferContent 11604 (0m0.011604s) in
lwlock__acquire__start (pg_regress/replica_identity) => [ 93557]
(pg_regress/generated)
!!W!! [ 93555]:3 LockFastPath 11214 (0m0.011214s) in
lwlock__acquire__start (pg_regress/identity)
!!W!! [ 93547]:3 LockFastPath 12307 (0m0.012307s) in
lwlock__acquire__start (pg_regress/security_label)
!!W!! [ 93546]:3 WALInsert 11800 (0m0.011800s) in
lwlock__acquire__start (pg_regress/brin) => [ 93551]
(pg_regress/replica_identity)
!!W!! [ 93555]:3 LockFastPath 12697 (0m0.012697s) in
lwlock__acquire__start (pg_regress/identity)
!!W!! [ 93551]:3 LockFastPath 10623 (0m0.010623s) in
lwlock__acquire__start (pg_regress/replica_identity)
!!W!! [ 93547]:3 LockFastPath 9137 (0m0.009137s) in
lwlock__acquire__start (pg_regress/security_label)
!!W!! [ 93552]:3 BufferContent 11916 (0m0.011916s) in
lwlock__acquire__start (pg_regress/rowsecurity) => [ 93547]
(pg_regress/security_label)
!!W!! [ 93550]:3 LockFastPath 10332 (0m0.010332s) in
lwlock__acquire__start (pg_regress/lock)
!!W!! [ 93552]:3 LockFastPath 12592 (0m0.012592s) in
lwlock__acquire__start (pg_regress/rowsecurity)
!!W!! [ 93549]:3 WALInsert 12528 (0m0.012528s) in
lwlock__acquire__start (pg_regress/matview)
!!W!! [ 93552]:3 LockFastPath 11045 (0m0.011045s) in
lwlock__acquire__start (pg_regress/rowsecurity)
!!W!! [ 93552]:3 LockFastPath 11348 (0m0.011348s) in
lwlock__acquire__start (pg_regress/rowsecurity)
!!W!! [ 93552]:3 WALInsert 10902 (0m0.010902s) in
lwlock__acquire__start (pg_regress/rowsecurity)
!!W!! [ 93544]:3 WALInsert 12443 (0m0.012443s) in
lwlock__acquire__start (pg_regress/privileges)
!!W!! [ 93548]:3 BufferContent 10951 (0m0.010951s) in
lwlock__acquire__start (pg_regress/collate)
!!W!! [ 93550]:3 LockFastPath 11762 (0m0.011762s) in
lwlock__acquire__start (pg_regress/lock) => [ 93552] (pg_regress/rowsecurity)
!!W!! [ 93558]:3 WALInsert 10980 (0m0.010980s) in
lwlock__acquire__start (pg_regress/join_hash) => [ 93553]
(pg_regress/object_address)
!!H!! [ 93539]:3 BufferContent 23160 (0m0.023160s) (pg_regress/gist)
!!W!! [ 93550]:3 LockFastPath 9454 (0m0.009454s) in
lwlock__acquire__start (pg_regress/lock)
!!W!! [ 93546]:3 LockFastPath 11757 (0m0.011757s) in
lwlock__acquire__start (pg_regress/brin)
!!W!! [ 93539]:3 WALInsert 12204 (0m0.012204s) in
lwlock__acquire__start (pg_regress/gist) => [ 93558] (pg_regress/join_hash)
!!H!! [ 93539]:3 BufferContent 25830 (0m0.025830s) (pg_regress/gist)
!!W!! [ 93550]:3 LockFastPath 12859 (0m0.012859s) in
lwlock__acquire__start (pg_regress/lock) => [ 93546] (pg_regress/brin)
!!W!! [ 93547]:3 LockFastPath 14416 (0m0.014416s) in
lwlock__acquire__start (pg_regress/security_label)
!!W!! [ 93552]:3 WALInsert 12684 (0m0.012684s) in
lwlock__acquire__start (pg_regress/rowsecurity)
!!W!! [ 93544]:3 WALInsert 13068 (0m0.013068s) in
lwlock__acquire__start (pg_regress/privileges)
!!W!! [ 93560]:3 BufferContent 10316 (0m0.010316s) in
lwlock__acquire__start (pg_regress/groupingsets) => [ 93549]
(pg_regress/matview)
!!W!! [ 93549]:3 WALInsert 9234 (0m0.009234s) in
lwlock__acquire__start (pg_regress/matview)
!!W!! [ 93543]:3 WALInsert 9567 (0m0.009567s) in
lwlock__acquire__start (pg_regress/spgist)
!!W!! [ 93552]:3 WALInsert 10605 (0m0.010605s) in
lwlock__acquire__start (pg_regress/rowsecurity)
!!W!! [ 93558]:3 WALInsert 10497 (0m0.010497s) in
lwlock__acquire__start (pg_regress/join_hash) => [ 93543] (pg_regress/spgist)
!!W!! [ 93550]:3 LockFastPath 13206 (0m0.013206s) in
lwlock__acquire__start (pg_regress/lock) => [ 93547] (pg_regress/security_label)
!!W!! [ 93541]:3 WALInsert 10136 (0m0.010136s) in
lwlock__acquire__start (pg_regress/gin)
!!W!! [ 93558]:3 CheckpointerComm 9836 (0m0.009836s) in
lwlock__acquire__start (pg_regress/join_hash)
!!W!! [ 93541]:3 WALInsert 12684 (0m0.012684s) in
lwlock__acquire__start (pg_regress/gin)
!!W!! [ 93544]:3 WALInsert 12938 (0m0.012938s) in
lwlock__acquire__start (pg_regress/privileges)
!!W!! [ 93544]:3 WALInsert 12433 (0m0.012433s) in
lwlock__acquire__start (pg_regress/privileges) => [ 93553]
(pg_regress/object_address)
!!W!! [ 93549]:3 LockFastPath 9029 (0m0.009029s) in
lwlock__acquire__start (pg_regress/matview)
!!W!! [ 93541]:3 WALInsert 12360 (0m0.012360s) in
lwlock__acquire__start (pg_regress/gin) => [ 93558] (pg_regress/join_hash)
!!W!! [ 93544]:3 WALInsert 14209 (0m0.014209s) in
lwlock__acquire__start (pg_regress/privileges) => [ 93558]
(pg_regress/join_hash)
!!W!! [ 93553]:3 WALInsert 13015 (0m0.013015s) in
lwlock__waitforvar__start (pg_regress/object_address)
!!W!! [ 93550]:3 LockFastPath 10663 (0m0.010663s) in
lwlock__acquire__start (pg_regress/lock) => [ 93549] (pg_regress/matview)
!!W!! [ 93539]:3 WALInsert 10015 (0m0.010015s) in
lwlock__acquire__start (pg_regress/gist) => [ 93544] (pg_regress/privileges)
!!W!! [ 93539]:3 WALInsert 9492 (0m0.009492s) in
lwlock__acquire__start (pg_regress/gist)
!!W!! [ 93549]:3 BufferContent 11579 (0m0.011579s) in
lwlock__acquire__start (pg_regress/matview) => [ 93546] (pg_regress/brin)
!!W!! [ 93554]:3 BufferContent 11492 (0m0.011492s) in
lwlock__acquire__start (pg_regress/tablesample)
!!W!! [ 93555]:3 LockFastPath 11019 (0m0.011019s) in
lwlock__acquire__start (pg_regress/identity)
!!W!! [ 93557]:3 LockFastPath 12212 (0m0.012212s) in
lwlock__acquire__start (pg_regress/generated)
!!W!! [ 93541]:3 WALInsert 9244 (0m0.009244s) in
lwlock__acquire__start (pg_regress/gin)
!!W!! [ 93544]:3 WALInsert 11228 (0m0.011228s) in
lwlock__acquire__start (pg_regress/privileges)
!!W!! [ 93555]:3 WALInsert 12778 (0m0.012778s) in
lwlock__acquire__start (pg_regress/identity)
!!W!! [ 93550]:3 ProcArray 12383 (0m0.012383s) in
lwlock__acquire__start (pg_regress/lock) => [ 93557] (pg_regress/generated)
!!W!! [ 93550]:3 LockFastPath 11860 (0m0.011860s) in
lwlock__acquire__start (pg_regress/lock)
!!W!! [ 93550]:3 LockFastPath 12140 (0m0.012140s) in
lwlock__acquire__start (pg_regress/lock)
!!W!! [ 93558]:3 CheckpointerComm 15540 (0m0.015540s) in
lwlock__acquire__start (pg_regress/join_hash) => [ 93557] (pg_regress/generated)
!!W!! [ 93544]:3 CheckpointerComm 14098 (0m0.014098s) in
lwlock__acquire__start (pg_regress/privileges) => [ 93557]
(pg_regress/generated)
!!W!! [ 93539]:3 WALInsert 10748 (0m0.010748s) in
lwlock__acquire__start (pg_regress/gist) => [ 93541] (pg_regress/gin)
!!W!! [ 93544]:3 WALInsert 12754 (0m0.012754s) in
lwlock__acquire__start (pg_regress/privileges) => [ 93541] (pg_regress/gin)
!!W!! [ 93543]:3 WALInsert 12607 (0m0.012607s) in
lwlock__acquire__start (pg_regress/spgist)
!!W!! [ 93548]:3 WALInsert 13317 (0m0.013317s) in
lwlock__acquire__start (pg_regress/collate)
!!W!! [ 93543]:3 WALInsert 12503 (0m0.012503s) in
lwlock__acquire__start (pg_regress/spgist)
!!W!! [ 93541]:3 WALInsert 9797 (0m0.009797s) in
lwlock__acquire__start (pg_regress/gin)
!!W!! [ 93560]:3 WALInsert 9348 (0m0.009348s) in
lwlock__acquire__start (pg_regress/groupingsets)
!!W!! [ 94107]:3 LockManager 14110 (0m0.014110s) in
lwlock__acquire__start (backend)
!!W!! [ 94100]:3 LockManager 16682 (0m0.016682s) in
lwlock__acquire__start (backend)
!!W!! [ 94108]:3 LockManager 16687 (0m0.016687s) in
lwlock__acquire__start (backend)
!!H!! [ 94098]:3 LockFastPath 22730 (0m0.022730s) (backend)
!!H!! [ 94106]:3 BufferMapping 23213 (0m0.023213s) (backend)
!!W!! [ 94095]:3 LockManager 12137 (0m0.012137s) in
lwlock__acquire__start (backend)
!!H!! [ 94100]:3 BufferContent 21987 (0m0.021987s) (backend)
!!H!! [ 94096]:3 BufferContent 22058 (0m0.022058s) (backend)
!!H!! [ 94097]:3 LockFastPath 20903 (0m0.020903s) (backend)
!!W!! [ 94104]:3 LockManager 13222 (0m0.013222s) in
lwlock__acquire__start (backend)
!!H!! [ 94093]:3 LockFastPath 21984 (0m0.021984s) (backend)
!!W!! [ 94105]:3 LockManager 9312 (0m0.009312s) in
lwlock__acquire__start (pg_regress/xmlmap)
!!W!! [ 94100]:3 LockManager 12146 (0m0.012146s) in
lwlock__acquire__start (backend)
!!W!! [ 94107]:3 LockManager 12275 (0m0.012275s) in
lwlock__acquire__start (backend)
!!H!! [ 94098]:3 LockFastPath 21649 (0m0.021649s) (backend)
!!W!! [ 94096]:3 LockFastPath 10387 (0m0.010387s) in
lwlock__acquire__start (backend)
!!W!! [ 94101]:3 LockFastPath 9756 (0m0.009756s) in
lwlock__acquire__start (pg_regress/tsearch)
!!W!! [ 94103]:3 LockManager 13486 (0m0.013486s) in
lwlock__acquire__start (pg_regress/foreign_data) => [ 94108]
(pg_regress/advisory_lock)
!!W!! [ 94094]:3 LockFastPath 14176 (0m0.014176s) in
lwlock__acquire__start (pg_regress/foreign_key)
!!W!! [ 94109]:3 LockFastPath 13092 (0m0.013092s) in
lwlock__acquire__start (pg_regress/indirect_toast)
!!W!! [ 94097]:3 LockFastPath 12691 (0m0.012691s) in
lwlock__acquire__start (pg_regress/dependency) => [ 94106]
(pg_regress/functional_deps)
!!W!! [ 94096]:3 BufferContent 13705 (0m0.013705s) in
lwlock__acquire__start (pg_regress/cluster) => [ 94093]
(pg_regress/select_views)
!!W!! [ 94107]:3 LockFastPath 13111 (0m0.013111s) in
lwlock__acquire__start (pg_regress/equivclass)
!!W!! [ 94093]:3 LockFastPath 12981 (0m0.012981s) in
lwlock__acquire__start (pg_regress/select_views) => [ 94101]
(pg_regress/tsearch)
!!W!! [ 94103]:3 WALInsert 12883 (0m0.012883s) in
lwlock__waitforvar__start (pg_regress/foreign_data)
!!W!! [ 94109]:3 WALInsert 11049 (0m0.011049s) in
lwlock__acquire__start (pg_regress/indirect_toast)
!!W!! [ 94214]:3 LockManager 9447 (0m0.009447s) in
lwlock__acquire__start (pg_regress/polymorphism)
!!W!! [ 94211]:3 LockManager 15060 (0m0.015060s) in
lwlock__acquire__start (pg_regress/conversion)
!!W!! [ 94219]:3 LockManager 13978 (0m0.013978s) in
lwlock__acquire__start (pg_regress/largeobject)
!!H!! [ 94204]:3 LockFastPath 23217 (0m0.023217s)
(pg_regress/plancache)
!!W!! [ 94221]:3 XidGen 11833 (0m0.011833s) in
lwlock__acquire__start (pg_regress/xml)
!!W!! [ 94214]:3 WALInsert 12746 (0m0.012746s) in
lwlock__acquire__start (pg_regress/polymorphism)
!!W!! [ 94216]:3 BufferContent 15181 (0m0.015181s) in
lwlock__acquire__start (pg_regress/truncate) => [ 94206] (pg_regress/copy2)
!!W!! [ 94207]:3 BufferContent 9067 (0m0.009067s) in
lwlock__acquire__start (pg_regress/temp)
!!H!! [ 94219]:3 BufferMapping 21140 (0m0.021140s)
(pg_regress/largeobject)
!!W!! [ 94218]:3 BufferContent 24987 (0m0.024987s) in
lwlock__acquire__start (pg_regress/returning) => [ 94206] (pg_regress/copy2)
!!W!! [ 94211]:3 LockFastPath 10315 (0m0.010315s) in
lwlock__acquire__start (pg_regress/conversion)
!!W!! [ 94207]:3 LockFastPath 10289 (0m0.010289s) in
lwlock__acquire__start (pg_regress/temp) => [ 94211] (pg_regress/conversion)
!!W!! [ 94209]:3 BufferContent 14920 (0m0.014920s) in
lwlock__acquire__start (pg_regress/rangefuncs) => [ 94221] (pg_regress/xml)
!!W!! [ 94220]:3 LockFastPath 17482 (0m0.017482s) in
lwlock__acquire__start (pg_regress/rowtypes)
!!W!! [ 94213]:3 LockFastPath 11673 (0m0.011673s) in
lwlock__acquire__start (pg_regress/sequence)
!!W!! [ 94219]:3 LockFastPath 13072 (0m0.013072s) in
lwlock__acquire__start (pg_regress/largeobject)
!!W!! [ 94212]:3 LockFastPath 12953 (0m0.012953s) in
lwlock__acquire__start (pg_regress/alter_table) => [ 94215] (pg_regress/with)
!!W!! [ 94209]:3 LockFastPath 12885 (0m0.012885s) in
lwlock__acquire__start (pg_regress/rangefuncs) => [ 94215] (pg_regress/with)
!!W!! [ 94207]:3 LockFastPath 13022 (0m0.013022s) in
lwlock__acquire__start (pg_regress/temp) => [ 94215] (pg_regress/with)
!!W!! [ 94221]:3 LockFastPath 9057 (0m0.009057s) in
lwlock__acquire__start (pg_regress/xml)
!!W!! [ 94206]:3 LockFastPath 24928 (0m0.024928s) in
lwlock__acquire__start (pg_regress/copy2) => [ 94215] (pg_regress/with)
!!W!! [ 94220]:3 WALInsert 10382 (0m0.010382s) in
lwlock__acquire__start (pg_regress/rowtypes)
!!W!! [ 94215]:3 BufferContent 10770 (0m0.010770s) in
lwlock__acquire__start (pg_regress/with)
!!W!! [ 94215]:3 LockFastPath 13352 (0m0.013352s) in
lwlock__acquire__start (pg_regress/with)
!!W!! [ 94221]:3 LockFastPath 9756 (0m0.009756s) in
lwlock__acquire__start (pg_regress/xml)
!!W!! [ 94204]:3 BufferContent 10755 (0m0.010755s) in
lwlock__acquire__start (pg_regress/plancache) => [ 94213] (pg_regress/sequence)
!!W!! [ 94213]:3 CheckpointerComm 11483 (0m0.011483s) in
lwlock__acquire__start (pg_regress/sequence) => [ 94216] (pg_regress/truncate)
!!W!! [ 94214]:3 LockFastPath 12342 (0m0.012342s) in
lwlock__acquire__start (pg_regress/polymorphism)
!!W!! [ 94219]:3 LockFastPath 9477 (0m0.009477s) in
lwlock__acquire__start (pg_regress/largeobject) => [ 94206] (pg_regress/copy2)
!!W!! [ 94212]:3 LockFastPath 13289 (0m0.013289s) in
lwlock__acquire__start (pg_regress/alter_table) => [ 94206] (pg_regress/copy2)
!!W!! [ 94220]:3 LockFastPath 9445 (0m0.009445s) in
lwlock__acquire__start (pg_regress/rowtypes) => [ 94208] (pg_regress/domain)
!!W!! [ 94204]:3 ProcArray 11570 (0m0.011570s) in
lwlock__acquire__start (pg_regress/plancache) => [ 94215] (pg_regress/with)
!!W!! [ 94212]:3 LockFastPath 10229 (0m0.010229s) in
lwlock__acquire__start (pg_regress/alter_table)
!!W!! [ 94210]:3 LockFastPath 12291 (0m0.012291s) in
lwlock__acquire__start (pg_regress/prepare)
!!W!! [ 94213]:3 WALInsert 12225 (0m0.012225s) in
lwlock__waitforvar__start (pg_regress/sequence)
!!W!! [ 94212]:3 LockFastPath 11271 (0m0.011271s) in
lwlock__acquire__start (pg_regress/alter_table)
!!W!! [ 94205]:3 LockFastPath 18453 (0m0.018453s) in
lwlock__acquire__start (pg_regress/plpgsql)
!!W!! [ 94212]:3 LockFastPath 12136 (0m0.012136s) in
lwlock__acquire__start (pg_regress/alter_table) => [ 94207] (pg_regress/temp)
!!W!! [ 94220]:3 BufferContent 9292 (0m0.009292s) in
lwlock__acquire__start (pg_regress/rowtypes) => [ 94213] (pg_regress/sequence)
!!W!! [ 94212]:3 ProcArray 12233 (0m0.012233s) in
lwlock__acquire__start (pg_regress/alter_table) => [ 94206] (pg_regress/copy2)
!!W!! [ 94218]:3 LockFastPath 10142 (0m0.010142s) in
lwlock__acquire__start (pg_regress/returning) => [ 94205] (pg_regress/plpgsql)
!!W!! [ 94205]:3 LockFastPath 12941 (0m0.012941s) in
lwlock__acquire__start (pg_regress/plpgsql) => [ 94216] (pg_regress/truncate)
!!W!! [ 94213]:3 LockFastPath 10196 (0m0.010196s) in
lwlock__acquire__start (pg_regress/sequence)
!!W!! [ 94208]:3 LockFastPath 16612 (0m0.016612s) in
lwlock__acquire__start (pg_regress/domain) => [ 94216] (pg_regress/truncate)
!!W!! [ 94209]:3 LockFastPath 13430 (0m0.013430s) in
lwlock__acquire__start (pg_regress/rangefuncs) => [ 94216] (pg_regress/truncate)
!!W!! [ 94207]:3 LockFastPath 14024 (0m0.014024s) in
lwlock__acquire__start (pg_regress/temp)
!!W!! [ 94220]:3 BufferContent 11345 (0m0.011345s) in
lwlock__acquire__start (pg_regress/rowtypes)
!!W!! [ 94220]:3 WALInsert 11898 (0m0.011898s) in
lwlock__waitforvar__start (pg_regress/rowtypes)
!!W!! [ 94207]:3 LockFastPath 11065 (0m0.011065s) in
lwlock__acquire__start (pg_regress/temp)
!!W!! [ 94209]:3 LockFastPath 12091 (0m0.012091s) in
lwlock__acquire__start (pg_regress/rangefuncs) => [ 94217] (pg_regress/limit)
!!W!! [ 94204]:3 BufferContent 13281 (0m0.013281s) in
lwlock__acquire__start (pg_regress/plancache) => [ 94205] (pg_regress/plpgsql)
!!W!! [ 94207]:3 LockFastPath 10086 (0m0.010086s) in
lwlock__acquire__start (pg_regress/temp) => [ 94208] (pg_regress/domain)
!!W!! [ 94208]:3 LockFastPath 10565 (0m0.010565s) in
lwlock__acquire__start (pg_regress/domain)
!!W!! [ 94207]:3 LockFastPath 10158 (0m0.010158s) in
lwlock__acquire__start (pg_regress/temp)
!!W!! [ 94209]:3 LockFastPath 9165 (0m0.009165s) in
lwlock__acquire__start (pg_regress/rangefuncs)
!!W!! [ 94216]:3 LockFastPath 13982 (0m0.013982s) in
lwlock__acquire__start (pg_regress/truncate)
!!W!! [ 94207]:3 LockFastPath 9432 (0m0.009432s) in
lwlock__acquire__start (pg_regress/temp)
!!W!! [ 94206]:3 BufferContent 12128 (0m0.012128s) in
lwlock__acquire__start (pg_regress/copy2) => [ 94222] (pg_regress/temp)
!!W!! [ 94213]:3 LockFastPath 9740 (0m0.009740s) in
lwlock__acquire__start (pg_regress/sequence) => [ 94205] (pg_regress/plpgsql)
!!W!! [ 94212]:3 LockManager 19423 (0m0.019423s) in
lwlock__acquire__start (pg_regress/alter_table)
!!W!! [ 94213]:3 LockFastPath 10195 (0m0.010195s) in
lwlock__acquire__start (pg_regress/sequence)
!!W!! [ 94216]:3 BufferContent 10278 (0m0.010278s) in
lwlock__acquire__start (pg_regress/truncate) => [ 94221] (pg_regress/xml)
!!W!! [ 94221]:3 BufferContent 9971 (0m0.009971s) in
lwlock__acquire__start (pg_regress/xml)
!!W!! [ 94222]:3 LockFastPath 12113 (0m0.012113s) in
lwlock__acquire__start (pg_regress/temp)
!!W!! [ 94212]:3 LockFastPath 10239 (0m0.010239s) in
lwlock__acquire__start (pg_regress/alter_table)
!!W!! [ 94206]:3 LockFastPath 12795 (0m0.012795s) in
lwlock__acquire__start (pg_regress/copy2)
!!W!! [ 94205]:3 LockFastPath 13019 (0m0.013019s) in
lwlock__acquire__start (pg_regress/plpgsql)
!!W!! [ 94218]:3 LockFastPath 9072 (0m0.009072s) in
lwlock__acquire__start (pg_regress/returning)
!!W!! [ 94213]:3 BufferContent 12120 (0m0.012120s) in
lwlock__acquire__start (pg_regress/sequence) => [ 94206] (pg_regress/copy2)
!!W!! [ 94206]:3 WALInsert 9498 (0m0.009498s) in
lwlock__acquire__start (pg_regress/copy2)
!!W!! [ 94205]:3 BufferContent 9796 (0m0.009796s) in
lwlock__acquire__start (pg_regress/plpgsql) => [ 94220] (pg_regress/rowtypes)
!!H!! [ 94208]:3 BufferContent 32324 (0m0.032324s)
(pg_regress/domain)
!!H!! [ 92986]:6 Checkpoint 195043 (0m0.195043s) (checkpointer)
^C
held locks: all procs tranche mode count total
avg variance min max
H LW_EXCLUSIVE (all) E 10438060 153077259
14 37035 1 195043
H LW_SHARED (all) S 14199902 65466934
4 5318 1 44030
all procs by tranche tranche mode count total
avg variance min max
H tranche (all) S 14199902 65466934
4 5318 1 44030
H tranche (all) E 10438060 153077259
14 37035 1 195043
H tranche OidGen E 22147 103232
4 531 1 2171
H tranche XidGen E 16854 89669
5 171 1 589
H tranche ProcArray E 17940 135246
7 2004 1 3742
H tranche ProcArray S 211370 1235489
5 4752 1 17127
H tranche SInvalRead S 99493 725391
7 9185 1 12673
H tranche SInvalWrite E 77449 420919
5 3552 1 10383
H tranche WALWrite E 15223 313859
20 21610 1 6725
H tranche Checkpoint E 11 220028
20002 3384533934 575 195043
H tranche XactSLRU E 15554 84989
5 106 1 364
H tranche XactSLRU S 52855 283102
5 4611 1 11451
H tranche MultiXactGen S 15175 78839
5 5860 1 7473
H tranche RelCacheInit E 262 39876
152 600892 10 12422
H tranche CheckpointerComm E 44708 229854
5 8003 1 17832
H tranche BackgroundWorker S 12537 56827
4 49 1 63
H tranche ReplicationSlotControl S 4995 32067
6 274 1 1001
H tranche WALInsert E 1850616 8229072
4 1064 1 12136
H tranche BufferContent E 2507692 109886361
43 135113 1 32324
H tranche BufferContent S 6999227 34464940
4 6818 1 44030
H tranche BufferIO E 35962 1380730
38 27687 2 15747
H tranche LockFastPath E 5461685 29651676
5 8256 1 24015
H tranche LockFastPath S 23309 67641
2 1682 1 5143
H tranche BufferMapping E 36240 166423
4 164 1 1115
H tranche BufferMapping S 6774414 27856202
4 4234 1 26939
H tranche LockManager E 310667 1676372
5 3080 1 14857
H tranche LockManager S 1343 318105
236 219042 1 9569
H tranche PredicateLockManager S 991 329533
332 235767 1 2523
H tranche PredicateLockManager E 147 117256
797 318798 1 2082
H tranche ParallelHashJoin E 1019 79453
77 12256 1 545
H tranche ParallelQueryDSA E 4941 61340
12 4662 1 750
H tranche PerSessionRecordType E 138 32188
233 10200 1 372
H tranche SharedTidBitmap E 9480 53626
5 73 1 73
wait locks: all procs tranche mode count total
avg variance min max
W LW_EXCLUSIVE (all) E 54185 14062734
259 1850265 1 44177
W LW_SHARED (all) S 3668 1116022
304 1527261 2 18642
all procs by tranche tranche mode count total
avg variance min max
W tranche (all) S 3668 1116022
304 1527261 2 18642
W tranche (all) E 54185 14062734
259 1850265 1 44177
W tranche OidGen E 106 24620
232 1570427 2 12876
W tranche XidGen E 83 51753
623 4935395 12 12288
W tranche ProcArray E 1110 268263
241 771505 2 11570
W tranche ProcArray S 1434 342987
239 950375 2 14862
W tranche SInvalRead E 122 24227
198 905376 9 10329
W tranche SInvalWrite E 510 121351
237 394378 3 7513
W tranche WALWrite E 147 39834
270 1325551 2 12831
W tranche XactSLRU E 264 58258
220 764310 2 9765
W tranche XactSLRU S 205 16888
82 32431 10 2437
W tranche CheckpointerComm E 255 96986
380 3371385 3 15540
W tranche WALInsert E 9839 2393229
243 1180294 2 14209
W tranche BufferContent E 3012 1726543
573 3869409 2 28186
W tranche BufferContent S 1664 657855
395 2185694 2 18642
W tranche LockFastPath E 28314 6327801
223 1278053 1 26133
W tranche LockFastPath S 87 59401
682 3703217 19 9454
W tranche BufferMapping E 151 16223
107 81146 9 2035
W tranche BufferMapping S 151 29168
193 1277585 2 13056
W tranche LockManager E 7223 2764392
382 2514863 2 44177
W tranche ParallelHashJoin E 128 10237
79 6014 8 489
W tranche ParallelQueryDSA E 233 10859
46 1176 2 205
W tranche SharedTidBitmap E 2426 116776
48 872 2 224
------
------
Pass 5: run completed in 20usr/80sys/165102real ms.
lwlock_hold_durations.stp
Description: Binary data
