[Performance] Optimize / Reduce (expensive) log events

[JanThiel]

Is your feature request related to a problem? Please describe. We currently profile our WP setup. Decalog popped up as a source of too much rendering-time on nearly all requests.

See the profiling chart on the right in light and dark green. In this request the CoreListener::plugin_close causes about 40% of the rendering time of that page. All Decalog is at about 52% of this single request. The remaining time comes from DatabaseListener::db_monitoring_close.

The source is within the CoreListener::plugin_close with its calls to plugin_update and theme_update causing HTTP requests to the external repos. As we all know that HTTP requests are ~bad and evil~ slow these operations should be used rarely and never in frontend or AJAX requests. DatabaseListener::db_monitoring_close does uncached SQL queries. Even something I would like to skip performancewise ;-).

Describe the solution you'd like There are two solutions coming into my mind:

1. General approach: We do not have any metrics provider configured by choice in this environment. So why are metrics even collected? The plugin_close method as well as db_monitoring_close only work on counters which are only relevant if a metric provider is configured, correct? Could we add a layer of "check what to collect before collecting it"? Like collect_metrics():true|false and collect_events():true|false and add them around the proper functions before executing and hooking stuff? Should reduce the footprint of the plugin to the only required level.

2. For this particular case: Limit the execution of the plugin functions to authenticated admin calls with the capabilities to actually update plugins.

Additional context WPMU 6.0.2 PHP 7.4.

[JanThiel]

Just to add for sure regarding the plugin & theme update: This only happens if the transients are not filled. So it's not a general issue. But it happens from time to time.

[Pierre-Lannoy]

Hi @JanThiel !

Thanks for this. As usual, perfectly documented ❤️

I will try to address all your underlying questions…

First of all, CoreListener::plugin_close calls wp_update_plugins() and wp_update_themes() only if it can't find the corresponding transients (update_plugins and update_themes). If these transients are available, these functions are not called. From my tests on live sites, the calls are made less than 1 time per 6 hours… Maybe do you have issues with your transients? - edit : just saw your comment appeared as I was typing 😄 Remark about the wp_update_plugins() and wp_update_themes() calls: contrary to what their names suggest, they "do" not update things, they just verify if updates are available…

DatabaseListener::db_monitoring_close: yes it do some uncached/uncachable queries…

But note too, for the 2 *_close functions: they are called in the shutdown hook. It has no impact in the page rendering time because when this hook is "triggered", the http response (headers, body, etc.) is already sent to the client. Nevertheless, I know and understand it consume resources.

Your first solution is absolutely what I will implement, because there's more people using only events logging features… (it was not MY case when I first pushes the monitoring - bad assumption from my side 😉 )

The second solution ( forwp_update_plugins() and wp_update_themes() calls) seems to me a bit irrelevant because, once again, these functions do not update plugins and themes. If you see more than 1 call every 5-6 hours, there's another issue.

[JanThiel]

👍 Sounds perfect to me. And please don't call it "bad assumption" it's just that other people have other usecases ;-) So i'ts merely an evolution. And that's what OpenSource is all about, isn't it? Contributing and developing stuff together.

And yea, there was as well something off with these transients on our setup in some edge cases 👼. Fixed that already. But that was still nice to uncover these things in Profiling.

Just for some background info and experience from our past: We once tested and used WSAL from Robert and White Hat Sec for some time. It kind of does the same as Decalog but focussed on Audit logging ;-). They as well triggered several performance issues back then due to the way WordPress is built and some events are constructed. All these things don't matter in "small" setups. But whenever something scales, like media files or entries, these logging event do have a relevant impact. In particular we had the issue with WP Menus. As each item save triggers a log event it tends to create timeouts with very very very huge menus with lots of menu items. Thus rendering the menus impossible to save. I just wanted to share that to avoid these pitfalls with Decalog :-)

Have a great weekend!

[Pierre-Lannoy]

And please don't call it "bad assumption" it's just that other people have other usecases ;-) So i'ts merely an evolution. And that's what OpenSource is all about, isn't it? Contributing and developing stuff together.

Definitely in deep agreement with this ❤️

Regarding your experience with WSAL, I see what you have in mind. Nevertheless, I do not blame them. They made a choice of something simple (simplistic?) that match with mainstream needs. That's not the case with DecaLog: I've made the choice of something efficient, powerful and "deeper" (so, more technical, unfortunately). And I want to do everything to be as efficient as possible. Your remarks and suggestions on this matter are unvaluable for me… So thanks again!

[Pierre-Lannoy]

Hello @JanThiel ! It's never too late to do the right thing. This "feature" will be in next release (3.7.0). Thanks again for your invaluable help and insights 🥇

[JanThiel]

@Pierre-Lannoy Just feeding you ideas and wishes :-)

Thank you very much for providing such an extensive and amazing support and ongoing development.

[Pierre-Lannoy]

Version 3.7.0 released. This feature is implemented. Many thanks for the suggestion 😉