BUG #14159: PostgreSQL 9.6 parallel scan consume very high mutex lock

From: digoal(at)126(dot)com
To: pgsql-bugs(at)postgresql(dot)org
Subject: BUG #14159: PostgreSQL 9.6 parallel scan consume very high mutex lock
Date: 2016-05-25 11:51:53
Message-ID: 20160525115153.19432.69752@wrigleys.postgresql.org
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

The following bug has been logged on the website:

Bug reference: 14159
Logged by: Zhou Digoal
Email address: digoal(at)126(dot)com
PostgreSQL version: 9.6beta1
Operating system: CentOS 6.x x64
Description:

My test environment:
CentOS 6
64 CORE cpu

this is not use parallel
postgres=# alter table t_bit2 set (parallel_degree=0);
ALTER TABLE
Time: 0.335 ms

postgres=# select count(*) from t_bit2 ;
count
------------
1600000000
(1 row)
Time: 141377.100 ms

and the perftop is
```
PerfTop: 1075 irqs/sec kernel:21.5% exact: 0.0% [1000Hz cycles],
(all, 64 CPUs)
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

samples pcnt function DSO
_______ _____ ________________________________
_________________________________________________________________________________

2493.00 15.2% heap_getnext
/home/digoal/pgsql9.6/bin/postgres

1988.00 12.1% copy_user_generic_string
[kernel.kallsyms]

1265.00 7.7% advance_aggregates
/home/digoal/pgsql9.6/bin/postgres

931.00 5.7% ExecProject
/home/digoal/pgsql9.6/bin/postgres

891.00 5.4% heapgetpage
/home/digoal/pgsql9.6/bin/postgres

864.00 5.3% HeapTupleSatisfiesMVCC
/home/digoal/pgsql9.6/bin/postgres

744.00 4.5% ExecProcNode
/home/digoal/pgsql9.6/bin/postgres

717.00 4.4% advance_transition_function
/home/digoal/pgsql9.6/bin/postgres

697.00 4.2% ExecScan
/home/digoal/pgsql9.6/bin/postgres

581.00 3.5% SeqNext
/home/digoal/pgsql9.6/bin/postgres

576.00 3.5% ExecStoreTuple
/home/digoal/pgsql9.6/bin/postgres

446.00 2.7% ExecClearTuple
/home/digoal/pgsql9.6/bin/postgres

378.00 2.3% MemoryContextReset
/home/digoal/pgsql9.6/bin/postgres

364.00 2.2% hash_search_with_hash_value
/home/digoal/pgsql9.6/bin/postgres

364.00 2.2% ExecAgg
/home/digoal/pgsql9.6/bin/postgres

307.00 1.9% CheckForSerializableConflictOut
/home/digoal/pgsql9.6/bin/postgres

296.00 1.8% fetch_input_tuple
/home/digoal/pgsql9.6/bin/postgres

217.00 1.3% int8inc
/home/digoal/pgsql9.6/bin/postgres

217.00 1.3% XidInMVCCSnapshot
/home/digoal/pgsql9.6/bin/postgres

169.00 1.0% _mdfd_getseg
/home/digoal/pgsql9.6/bin/postgres

```
And when use 64 parallel

postgres=# alter table t_bit2 set (parallel_degree=64);
ALTER TABLE
Time: 0.180 ms
postgres=# explain select count(*) from t_bit2 ;
QUERY PLAN

-----------------------------------------------------------------------------------------------
Finalize Aggregate (cost=12108923.92..12108923.93 rows=1 width=8)
-> Gather (cost=12108917.35..12108923.76 rows=64 width=8)
Workers Planned: 64
-> Partial Aggregate (cost=12107917.35..12107917.36 rows=1
width=8)
-> Parallel Seq Scan on t_bit2 (cost=0.00..12046131.88
rows=24714188 width=0)
(5 rows)

Time: 0.338 ms
postgres=# select count(*) from t_bit2 ;
count
------------
1600000000
(1 row)

Time: 37181.297 ms

the perftop is
```
PerfTop: 47649 irqs/sec kernel:83.5% exact: 0.0% [1000Hz cycles],
(all, 64 CPUs)
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

samples pcnt function DSO
_______ _____ _______________________________
______________________________________________________________________

436271.00 76.5% __mutex_lock_slowpath [kernel.kallsyms]

13897.00 2.4% _spin_lock [kernel.kallsyms]

11159.00 2.0% heap_getnext
/home/digoal/pgsql9.6/bin/postgres
6929.00 1.2% copy_user_generic_string [kernel.kallsyms]

6497.00 1.1% advance_aggregates
/home/digoal/pgsql9.6/bin/postgres
5786.00 1.0% mutex_lock [kernel.kallsyms]

5133.00 0.9% mutex_unlock [kernel.kallsyms]

4862.00 0.9% ExecProject
/home/digoal/pgsql9.6/bin/postgres
4351.00 0.8% advance_transition_function
/home/digoal/pgsql9.6/bin/postgres
4130.00 0.7% LWLockAcquire
/home/digoal/pgsql9.6/bin/postgres
4119.00 0.7% heapgetpage
/home/digoal/pgsql9.6/bin/postgres
3751.00 0.7% ExecScan
/home/digoal/pgsql9.6/bin/postgres
3275.00 0.6% ExecProcNode
/home/digoal/pgsql9.6/bin/postgres
3159.00 0.6% HeapTupleSatisfiesMVCC
/home/digoal/pgsql9.6/bin/postgres
3123.00 0.5% mutex_spin_on_owner [kernel.kallsyms]

```

when i set paralle degree to 16

postgres=# alter table t_bit2 set (parallel_degree=16);
ALTER TABLE
Time: 0.433 ms
postgres=# select count(*) from t_bit2 ;
count
------------
1600000000
(1 row)

Time: 9534.304 ms

the perf top is
```
PerfTop: 16436 irqs/sec kernel:21.9% exact: 0.0% [1000Hz cycles],
(all, 64 CPUs)
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

samples pcnt function DSO
_______ _____ _______________________________
______________________________________________________________________

10020.00 11.0% heap_getnext
/home/dege.zzz/pgsql9.6/bin/postgres
9804.00 10.8% copy_user_generic_string [kernel.kallsyms]

6239.00 6.9% advance_aggregates
/home/dege.zzz/pgsql9.6/bin/postgres
4666.00 5.1% ExecProject
/home/dege.zzz/pgsql9.6/bin/postgres
4496.00 5.0% heapgetpage
/home/dege.zzz/pgsql9.6/bin/postgres
4419.00 4.9% HeapTupleSatisfiesMVCC
/home/dege.zzz/pgsql9.6/bin/postgres
3891.00 4.3% ExecClearTuple
/home/dege.zzz/pgsql9.6/bin/postgres
3703.00 4.1% ExecProcNode
/home/dege.zzz/pgsql9.6/bin/postgres
3620.00 4.0% advance_transition_function
/home/dege.zzz/pgsql9.6/bin/postgres
3385.00 3.7% ExecScan
/home/dege.zzz/pgsql9.6/bin/postgres
2855.00 3.1% ExecStoreTuple
/home/dege.zzz/pgsql9.6/bin/postgres
2645.00 2.9% SeqNext
/home/dege.zzz/pgsql9.6/bin/postgres
```

why?

best regards,
digoal

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message Hao Lee 2016-05-25 12:24:00 Re: BUG #14158: PostgreSQL 9.6 bloom don't support unlogged table?
Previous Message vigneshwaran balaji 2016-05-25 11:20:50 Re: Postgres Help - Reg