Re: BUG #14530: Logical Decoding Slowness

On 2017-02-09 06:55:00 +0000, Huan Ruan wrote:
> Hi Andres
>
>
> > Unfortunately perf files can't be interpreted on other systems unless
> > you added all the referenced object files to it using perf archive.
> >
>
> Sorry this was my first time using perf for profiling so didn't know that.
> Also, the profile was collected without Postgres debuginfo installed. If
> you need that or something else please let me know.
>
>
> > Could you perhaps just send the first few lines of the report?
> >
> > The first screen of 'perf report -n' for subtransaction case is,
>
> Samples: 247K of event 'cycles', Event count (approx.): 155149593065
> Children Self Samples Command Shared Object
> Symbol
> + 51.26% 0.00% 0 postgres [unknown]
> [.] 0x0000000003236e68
> + 48.66% 48.54% 117427 postgres postgres
> [.] CatalogCacheIdInvalidate
> + 38.44% 38.35% 92748 postgres postgres
> [.] hash_seq_search
> + 5.67% 5.66% 13683 postgres postgres
> [.] CallSyscacheCallbacks
> + 3.00% 2.99% 7234 postgres postgres
> [.] LocalExecuteInvalidationMessage
> + 1.00% 0.99% 2397 postgres postgres

Yea, that was what I was thinking - we're replaying more invalidations
than we'd need to, and we do so very frequently. That's quite
expensive. Hmmm.

> for create tables is,
>
> Samples: 342K of event 'cycles', Event count (approx.): 216348097599
> Children Self Samples Command Shared Object
> Symbol
> + 52.09% 0.00% 0 postgres [unknown]
> [.] 0x000000009754f3a8
> + 49.09% 48.98% 164831 postgres postgres
> [.] CatalogCacheIdInvalidate
> + 38.75% 38.67% 130091 postgres postgres
> [.] hash_seq_search
> + 4.92% 4.90% 16494 postgres postgres
> [.] CallSyscacheCallbacks
> + 3.20% 3.19% 10736 postgres postgres
> [.] LocalExecuteInvalidationMessage

Same here.

Let me ponder this for a bit.

Thanks,

Andres