Re: BUG #13493: pl/pgsql doesn't scale with cpus (PG9.3, 9.4)

On 2015-07-08 14:55:12 +0200, Andres Freund wrote:
> comparing stats between the 4 and 8 client runs shows (removing boring data):

> 4 clients:
> 109,655,985,749 stalled-cycles-frontend # 54.27% frontend cycles idle (27.79%)
> 41,664,400,828 branches # 458.558 M/sec (33.32%)
> 374,426,805 branch-misses # 0.90% of all branches (33.32%)

> 8 clients:
> 247,231,674,170 stalled-cycles-frontend # 67.04% frontend cycles idle (27.84%)
> 54,503,992,461 branches # 329.991 M/sec (33.39%)
> 761,911,056 branch-misses # 1.40% of all branches (33.38%)

looking at stalled-cycles-frontend, and branch-misses shows:

-e branch-misses
4:
+ 7.34% postgres plpgsql.so [.] plpgsql_exec_function
+ 6.33% postgres postgres [.] standard_ExecutorRun
+ 5.49% postgres postgres [.] SPI_push
+ 4.24% postgres libc-2.19.so [.] __memcpy_sse2_unaligned
+ 3.43% postgres postgres [.] ReleaseCachedPlan
+ 2.72% postgres plpgsql.so [.] exec_stmt
+ 2.07% postgres postgres [.] SPI_pop
+ 1.94% postgres postgres [.] ExecLimit
+ 1.94% postgres libc-2.19.so [.] __strcpy_sse2_unaligned
+ 1.59% postgres libc-2.19.so [.] _int_malloc
+ 1.46% postgres postgres [.] LWLockRelease
+ 1.33% postgres postgres [.] AllocSetAlloc
+ 1.17% postgres libc-2.19.so [.] _int_free
+ 1.08% postgres libc-2.19.so [.] memset
+ 1.00% postgres postgres [.] hash_search_with_hash_value
+ 0.99% postgres postgres [.] GetSnapshotData

8:

+ 10.66% pgbench libpq.so.5.9 [.] PQsocket
+ 8.40% pgbench libpthread-2.19.so [.] __libc_recv
+ 5.03% postgres plpgsql.so [.] plpgsql_exec_function
+ 3.00% postgres postgres [.] AllocSetAlloc
+ 2.86% postgres postgres [.] standard_ExecutorRun
+ 2.54% postgres plpgsql.so [.] exec_stmt
+ 2.45% postgres libc-2.19.so [.] __memcpy_sse2_unaligned
+ 2.27% postgres postgres [.] GetSnapshotData
+ 2.22% postgres postgres [.] ReleaseCachedPlan
+ 2.14% postgres postgres [.] OverrideSearchPathMatchesCurrent
+ 2.06% postgres postgres [.] SPI_push
+ 2.02% postgres postgres [.] SPI_pop
+ 1.92% postgres libc-2.19.so [.] _int_malloc
+ 1.86% postgres postgres [.] ExecLimit
+ 1.77% postgres postgres [.] SPI_connect
+ 1.74% postgres libc-2.19.so [.] __strcpy_sse2_unaligned

It's interesting to see that the limited size of the trace buffer leads
to previously perfectly predicted functions like PQsocket regularly
causing cache misses now... Interesting to see how GetSnapshotData()
rises in comparison.

OverrideSearchPathMatchesCurrent() is also curious, but perhaps not so
surprising considering it's chasing down a linked list - almost
impossible to predict.

-e stalled-cycles-frontend:
4:
+ 21.50% swapper [kernel.vmlinux] [k] intel_idle
+ 4.21% pgbench libpthread-2.19.so [.] __libc_recv
+ 2.68% postgres postgres [.] LWLockAcquire
+ 2.35% pgbench [kernel.vmlinux] [k] fput
+ 2.34% pgbench [kernel.vmlinux] [k] unix_stream_recvmsg
+ 2.03% pgbench [kernel.vmlinux] [k] system_call
+ 2.02% pgbench pgbench [.] threadRun
+ 1.82% pgbench [kernel.vmlinux] [k] system_call_after_swapgs
+ 1.73% postgres plpgsql.so [.] plpgsql_exec_function
+ 1.56% postgres postgres [.] LWLockRelease
+ 1.33% pgbench [kernel.vmlinux] [k] sys_recvfrom
+ 1.24% postgres libc-2.19.so [.] _int_malloc
+ 1.16% pgbench [vdso] [.] 0x00000000000008c9
+ 1.06% pgbench [kernel.vmlinux] [k] __fget
+ 1.04% postgres libc-2.19.so [.] _int_free
+ 1.02% pgbench libpthread-2.19.so [.] __pthread_enable_asynccancel

8:

+ 8.41% swapper [kernel.vmlinux] [k] intel_idle
+ 4.35% pgbench pgbench [.] threadRun
+ 3.56% pgbench libpthread-2.19.so [.] __libc_recv
+ 2.58% pgbench [kernel.vmlinux] [k] unix_stream_recvmsg
+ 1.99% postgres plpgsql.so [.] plpgsql_exec_function
+ 1.98% postgres postgres [.] AllocSetAlloc
+ 1.94% pgbench [kernel.vmlinux] [k] sys_recvfrom
+ 1.72% postgres postgres [.] LWLockAcquire
+ 1.66% pgbench pgbench [.] doCustom
+ 1.59% pgbench [kernel.vmlinux] [k] system_call_after_swapgs
+ 1.58% pgbench [kernel.vmlinux] [k] system_call
+ 1.51% pgbench [vdso] [.] __vdso_gettimeofday
+ 1.50% pgbench [kernel.vmlinux] [k] __fget
+ 1.21% postgres libc-2.19.so [.] memset
+ 1.11% postgres libc-2.19.so [.] _int_malloc
+ 1.08% postgres postgres [.] GetSnapshotData

(intel_idle is executed on a cpu when it's idle. Not surprising that it
shows up prominently, especially when not all cores are busy). It's
interesting to see how the locking functions are less prominent in the
-c8 case, and how overhead of allocation and plpgsql_exec_function
rises.