MIME-Version: 1.0
From: milist ujang <ujang.milist@gmail.com>
Date: Sat, 30 Sep 2017 06:07:06 +0700
Message-ID: 
 <CACG9ogzm-x3VP-7bBnKh-j-5W=wZ0UxwPvgtWAu=_icaHKgUFA@mail.gmail.com>
Subject: BDR, wal sender, high system cpu, mutex_lock_common
To: pgsql-performance@postgresql.org
Content-Type: multipart/alternative; boundary="94eb2c1c1a42797df3055a5c158c"
Precedence: bulk
Sender: pgsql-performance-owner@postgresql.org

--94eb2c1c1a42797df3055a5c158c
Content-Type: text/plain; charset="UTF-8"

Hi all,


I've an environment 9.4 + bdr:
PostgreSQL 9.4.4 on x86_64-unknown-linux-gnu, compiled by gcc (Debian
4.7.2-5) 4.7.2, 64-bit

kernel version:
3.2.0-4-amd64 #1 SMP Debian 3.2.65-1 x86_64 GNU/Linux

This is consolidation databases, in this machine there are around 250+ wal
sender processes.

top output revealed high system cpu:
%Cpu(s):  1.4 us, 49.7 sy,  0.0 ni, 48.8 id,  0.0 wa,  0.0 hi,  0.0 si,
 0.0 st

profiling cpu with perf:

perf top -e cpu-clock

Events: 142K cpu-clock
 82.37%  [kernel]            [k] __mutex_lock_common.isra.5
  4.49%  [kernel]            [k] do_raw_spin_lock
  2.23%  [kernel]            [k] mutex_lock
  2.16%  [kernel]            [k] mutex_unlock
  2.12%  [kernel]            [k] arch_local_irq_restore
  1.73%  postgres            [.] ValidXLogRecord
  0.87%  [kernel]            [k] __mutex_unlock_slowpath
  0.78%  [kernel]            [k] arch_local_irq_enable
  0.63%  [kernel]            [k] sys_recvfrom


finally get which processes (wal senders) that are using mutexes:

perf top -e task-clock -p 55382

Events: 697  task-clock
 88.08%  [kernel]  [k] __mutex_lock_common.isra.5
  3.27%  [kernel]  [k] do_raw_spin_lock
  2.34%  [kernel]  [k] arch_local_irq_restore
  2.10%  postgres  [.] ValidXLogRecord
  1.87%  [kernel]  [k] mutex_unlock
  1.87%  [kernel]  [k] mutex_lock
  0.47%  [kernel]  [k] sys_recvfrom

I think bdr is only reading wal file (current state is we behind current
wal lsn),
so why reading wal file needs mutex?

I wonder, is there kernel version has better handling mutexes?


-- 
regards

ujang jaenudin | DBA Consultant (Freelancer)
http://ora62.wordpress.com
http://id.linkedin.com/pub/ujang-jaenudin/12/64/bab

--94eb2c1c1a42797df3055a5c158c
Content-Type: text/html; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr">Hi all,<div><br></div><div><br></div><div>I&#39;ve an envi=
ronment 9.4 + bdr:=C2=A0</div><div>PostgreSQL 9.4.4 on x86_64-unknown-linux=
-gnu, compiled by gcc (Debian 4.7.2-5) 4.7.2, 64-bit</div><div><div><br></d=
iv><div>kernel version:</div><div>3.2.0-4-amd64 #1 SMP Debian 3.2.65-1 x86_=
64 GNU/Linux<br></div><div><br></div><div>This is consolidation databases, =
in this machine there are around 250+ wal sender processes.</div><div><br><=
/div><div><div>top output revealed high system cpu:</div><div>%Cpu(s): =C2=
=A01.4 us, 49.7 sy, =C2=A00.0 ni, 48.8 id, =C2=A00.0 wa, =C2=A00.0 hi, =C2=
=A00.0 si, =C2=A00.0 st</div><div><br></div><div><div>profiling cpu with pe=
rf:</div><div><br></div><div>perf top -e cpu-clock</div><div><br></div><div=
>Events: 142K cpu-clock</div><div>=C2=A082.37% =C2=A0[kernel] =C2=A0 =C2=A0=
 =C2=A0 =C2=A0 =C2=A0 =C2=A0[k] __mutex_lock_common.isra.5</div><div>=C2=A0=
 4.49% =C2=A0[kernel] =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0[k] do_raw_s=
pin_lock</div><div>=C2=A0 2.23% =C2=A0[kernel] =C2=A0 =C2=A0 =C2=A0 =C2=A0 =
=C2=A0 =C2=A0[k] mutex_lock</div><div>=C2=A0 2.16% =C2=A0[kernel] =C2=A0 =
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0[k] mutex_unlock</div><div>=C2=A0 2.12% =
=C2=A0[kernel] =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0[k] arch_local_irq_=
restore</div><div>=C2=A0 1.73% =C2=A0postgres =C2=A0 =C2=A0 =C2=A0 =C2=A0 =
=C2=A0 =C2=A0[.] ValidXLogRecord</div><div>=C2=A0 0.87% =C2=A0[kernel] =C2=
=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0[k] __mutex_unlock_slowpath</div><div=
>=C2=A0 0.78% =C2=A0[kernel] =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0[k] a=
rch_local_irq_enable</div><div>=C2=A0 0.63% =C2=A0[kernel] =C2=A0 =C2=A0 =
=C2=A0 =C2=A0 =C2=A0 =C2=A0[k] sys_recvfrom</div></div><div><br></div><div>=
<br></div><div>finally get which processes (wal senders)=C2=A0that are usin=
g mutexes:</div><div><br></div><div>perf top -e task-clock -p 55382</div><d=
iv><br></div><div>Events: 697 =C2=A0task-clock</div><div>=C2=A088.08% =C2=
=A0[kernel] =C2=A0[k] __mutex_lock_common.isra.5</div><div>=C2=A0 3.27% =C2=
=A0[kernel] =C2=A0[k] do_raw_spin_lock</div><div>=C2=A0 2.34% =C2=A0[kernel=
] =C2=A0[k] arch_local_irq_restore</div><div>=C2=A0 2.10% =C2=A0postgres =
=C2=A0[.] ValidXLogRecord</div><div>=C2=A0 1.87% =C2=A0[kernel] =C2=A0[k] m=
utex_unlock</div><div>=C2=A0 1.87% =C2=A0[kernel] =C2=A0[k] mutex_lock</div=
><div>=C2=A0 0.47% =C2=A0[kernel] =C2=A0[k] sys_recvfrom</div></div><div><b=
r></div><div>I think bdr is only reading wal file (current state is we behi=
nd current wal lsn),</div><div>so why reading wal file needs mutex?</div><d=
iv><br></div><div>I wonder, is there kernel version has better handling mut=
exes?=C2=A0</div><div><br></div><div><br></div>-- <br><div class=3D"gmail_s=
ignature">regards<br><br>ujang jaenudin | DBA Consultant (Freelancer)<br><a=
 href=3D"http://ora62.wordpress.com" target=3D"_blank">http://ora62.wordpre=
ss.com</a><br><a href=3D"http://id.linkedin.com/pub/ujang-jaenudin/12/64/ba=
b" target=3D"_blank">http://id.linkedin.com/pub/ujang-jaenudin/12/64/bab</a=
></div>
</div></div>

--94eb2c1c1a42797df3055a5c158c--