Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1ldrvm-0007T4-Mn for pgsql-performance@arkaria.postgresql.org; Tue, 04 May 2021 10:05:31 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.92) (envelope-from ) id 1ldrvk-0003eC-LQ for pgsql-performance@arkaria.postgresql.org; Tue, 04 May 2021 10:05:28 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1ldrFX-0005XH-SD for pgsql-performance@lists.postgresql.org; Tue, 04 May 2021 09:21:52 +0000 Received: from sonic308-56.consmr.mail.ne1.yahoo.com ([66.163.187.31]) by magus.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.92) (envelope-from ) id 1ldrFU-0000gA-W9 for pgsql-performance@postgresql.org; Tue, 04 May 2021 09:21:51 +0000 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s2048; t=1620120104; bh=J+6tsyllRpfk8z+FmaOxA6BDVIwboE3z4BnjBWjx70g=; h=From:Subject:To:Cc:References:Date:From:Subject:Reply-To; b=Lv/AHbFlrz8Sd7bEIxtDs4qbcRJ+fgKmYMhzhFO6R06YXNKEUyuV3R/NoVSJIpYpoJrqZEJbjzKGK1pMMRVyALctap0FoKhvUjKdGSETkgHhNf/jv/NUIlFwMJVleg9DHrGIOJWS5qKe5r+ECT1rCNBBAPis06RF8+6JU+4s8cpSLNaVy8Obse3xGhwx/ANqEHc2Df/i2w3QhtgOvzoQ0Ms8NIc0xyPhT1cJlF1JJEjPXZEUSjpxH65ONY8sY9VsVT/M9UXzB0bnUnxJh+1S6uMemXdP/iGLi5WD3wAkaE+VElqEd7VyM9WpEg4WWGmrlxRWiZPNCW0uAoGmkUAghA== X-SONIC-DKIM-SIGN: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s2048; t=1620120104; bh=AL7GikGeUDNkDCPZoSvd1Wr5d34nV9coOOrMM54tPe3=; h=X-Sonic-MF:From:Subject:To:Date:From:Subject; b=h2vsOLSD1gCJuf702vYAVmJoHyar2pcjmeyJm1gt/C+kc0wyUdoYqRDWi9+oS9Ws9cEjiPNkS/ZJgAlC2pqGlaEaRqsIr2byPrkY5HPENs+aZW5gX4rWGeOdgbndGULIu+Y1JQYnV/1ZAaCu97Z3U4C4i8edCFJqnDavBj40WM7JSzLelbQaIfZQ+B7udjwC/oJqlHrmfGMasXkKeOQYAKIot07qDf1ZSgcVFWZhGORmCfudag4T2WAbc/cDC7uPAhepUPhQn2PJg7LfNiClK0cfRHWIp3CrwxlEA43LgEOqJVYp5fcgFjc0k+N9c8xITt98Xely9m2z+SntCztMuA== X-YMail-OSG: AJzuOyYVM1m7xHkqoHRJ_J_9jSIP3U1EmXYbd30pkfxCn9U0ozwA6xd601MBs8R YndDCLFxS1EjeL9KSZgDLH43jbFbWpuFnNGzn72vMvxohD7NqXAXalKhziHpeG8_7ikZyKxXspIb RifTk_TlW.mpE__3ZHLksO6JiLUA7eH9QDnoyUcpqKLDmhS7Mr6w5gTKKJpKJDyg.IrlkxEFotlK FEGzVoHJRQbWymGDAwC2re9HYUgQJVT8S11OxBcvrx.12IGJ6jLz5bR7Sdg7kM9Idxx9Ob9HDL5M 95_3wT3q6GkS60AXN9YpOk.g1LWTK1_YlvdNgtWaeY3KU7h.w_gAddiLe_o_87eYFvW7Z67UJqng TP3voQJVmkdyZfn.HB69UzC3chok0eL2wLCRXsq7pndU.hmwbpconkICKTjaVpncJh6BRB46wEag nHyt0solKc2PWAvqXkm.aSXYz2mHpNH5ClJUF6DuIyI1u5oxZFrxs4EA0td7n5QL36JT_nndVYNS w6nsFK_v1kf1FYWvFjrvPmM6thhMSD8gPBAtylUGWOdV7CE0tzaxjDbJY.g4MHqNU7Ji0qXZ3HmF 5..Ssv5PSik06K4VKeLYutyTQVf2Usl52Krz9cZcJvOWCL7_w5Zg6MgIlVVSEaV_JD3nq9Muert9 RhzAJ.sPxs0fwYJb2YhELnidSe7juy3itm7o14ODBXvxYatsWbVS9QyQEFGeFKdGckSD5Tr0sMh5 sxD8Wu0B7Cy3sBxR4MRvrLHcPOnW_a_fpNp1xgSBQhveaxnUI1SbrGZJGpmLGgYnLEqMy2Ttmo8l ce5od9Vt337fI596bGzjbPpL2iwWBgUysywyw0CANzQ3UhmK8JmMw46CjBx5aBsNM.PqfX_lOgTz 2PlxY65e6bjnfz6.gpLxk5WXLdX7vcHYVcI4ROpi13IGeSeo1aWdCz5H4eBUVPdTHydOxOXBsAEN Tu3vhZSZ2znbchvCaPCUTtf4NW7M1vN17hVN7wNotpgPJdQ_N1PwyzIn65wKUOGN9r0yAsAWDBd8 kCISAS.SY7jXOuo1DXYDisagw2VGDJOJCk5Bld1S.dk_PLyIvH._WNYvudRUKOU4ITrxmNSmSLYL AMbMcpW.u5TTfuZKzVbMbtJlvUckF5slCLJL_ZsxAg9O2D8_28YuFmsQ_FlaCiVr66FN20PTz3O6 T9ImtFU8S7ImKb9WXCKuH4HBwOc7dD.kBwk_Cft9M7csf054DzvbaLxTlP7RabPxfbrQL396a4MG .wBur.lAf8hX6Ui36_vLo0U2S_qRbunGrNPnBRJyAVpR.om3j4Etn4VlJV1pravw1mxKEJlhFUMI ec7COLkFShox7KkprOPr6MZCHiGY1mJ6hupFeI9Z6Owh6i46QDtj6zSwXEDAn2Z_WH5UMOVZX.P1 XCKn3NWnozGMKDfxJx4W.ZsOCpWKPLlmyDbD.9mTRu3Hdt_AoZlKqdRp4RlSc8l8wzGJDZStd14X dfakl1G9wgz0ZepJnysTpOf_hjouh918NWvKfNU_yFdKAr95Z252d.33YfU5yXuXML0eG5yX5iby 0BXkIK3fbkSLMjyR4qSRf6itMEHCnhT30qIaUzNKIH2yEbQWyxxvKdOFck1ry1LD.7MzuDg.eUKI uCVaG9PBHBXOGe.o4A9BWMAK6Mt0WEjBj8L_l8hWUwz4f1iqbhWJ5LnH4C3VmfAHEff25jon0jK_ 3DvShup0lJqdPhcfLTNEX64qKzlwPGH5VwGqKX73p6kUTNlEOGsWhP4.68m9sgeWbNZstO9qNlAB DpiaE85CnjyontVjeF4n9ZN02XEo1JAUpJyIQmt2G0DideJKMMHVXg2p.Q6k3BgUXgYACqt4o_jq MEBSCR0u1cYEnTRKo9NWRR17nrZEv3etWT53Pusv9GTqoyCHd.qOgc4S2XBlYfLpTmEbBnEJlDAl s26iinK_zBeUh18bDkbrz21yd1547AIBuuySEg4HR0D_g94ACVcxrRYi8K3ts31MIV8RL4KCOGU5 0OVtveKityNGoGxclQKduqOP18FIGi.G4sh3ajZt__tUw7HA8aiQSyfxsJUrRhTEp8qCls1XNXR8 .jV4M2x97b.JPSIm36TfApW9Uw0zSGahEUFELq098fj1OQuwX6Voe.DrTpGeJfdKUI1OWjeQ3E96 yLU9.79_LPrk5_RBd78wXHdP7mVDI.WN3L9zYQyEsSIV._.GiJmMwAQikaMsd4vyxE4D52zjEtJs AQWDun3YPWdRqiSXzC_8UfkDO.d1Whf84GJFgXCsCqB3VawclTFAnVxj_.NcRHvcJNEi1baZJByR 0ds0aDFeShRJpQoraxEc0LlBI8b9GUCUjPTtct0okMhfoiPhw67qLnJDvJxjtAjEzyDlqbXuuF1l xuPJHn42Qmgj4t._TvDKE9vQvj1sQ.glCBaZQBIjc_WviEe8e_J3QKdar3RBBoCZTQljIGRlOm5J zWmjWsez8L95MrbuWE7O7GhkBuIbgEhE6DGWN2xZrEDQUNGe9f.KQ X-Sonic-MF: Received: from sonic.gate.mail.ne1.yahoo.com by sonic308.consmr.mail.ne1.yahoo.com with HTTP; Tue, 4 May 2021 09:21:44 +0000 Received: by kubenode512.mail-prod1.omega.ir2.yahoo.com (VZM Hermes SMTP Server) with ESMTPA ID 4b21fa1fecd40a0e6aa00a8aecadc042; Tue, 04 May 2021 09:21:36 +0000 (UTC) Content-Type: multipart/alternative; boundary="----sinikael-?=_1-16201200931320.9320682518431689" From: Alex Subject: Re: 15x slower PreparedStatement vs raw query X-Type: replyAll To: Justin Pryzby Cc: pgsql-performance@postgresql.org User-Agent: Desktop Message-Id: <49daf090ac5b1.96e1ada6021ee@yahoo.com> References: <3f8c88d8a6ef9.d82fa04cf610d.ref@yahoo.com> <3f8c88d8a6ef9.d82fa04cf610d@yahoo.com> <20210503201811.GA27406@telsasoft.com> Content-Transfer-Encoding: quoted-printable Date: Tue, 04 May 2021 09:21:32 +0000 MIME-Version: 1.0 X-Mailer: WebService/1.1.18231 mail.backend.jedi.jws.acl:role.jedi.acl.token.atz.jws.hermes.yahoo Apache-HttpAsyncClient/4.1.4 (Java/16) Content-Length: 5751 List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk ------sinikael-?=_1-16201200931320.9320682518431689 Content-Type: text/plain; format=flowed Content-Transfer-Encoding: 7bit Shouldn't this process be automatic based on some heuristics? Saving 10ms planning but costing 14s execution is catastrophic. For example, using some statistics to limit planner time to some percent of of previous executions. This way, if query is fast, planning is fast, but if query is slow, more planning can save huge execution time. This is a better general usage option and should be enabled by default, and users who want fast planning should set the variable to use the generic plan. Justin Pryzby wrote: On Sun, May 02, 2021 at 07:45:26PM +0000, Alex wrote: PreparedStatement: 15s Raw query with embedded params: 1s See issue on github with query and explain analyze: https://github.com/pgjdbc/pgjdbc/issues/2145 | ..PostgreSQL Version? 12 |Prepared statement |... |Planning Time: 11.596 ms |Execution Time: 14799.266 ms | |Raw statement |Planning Time: 22.685 ms |Execution Time: 1012.992 ms The prepared statemnt has 2x faster planning time, which is what it's meant to improve. The execution time is slower, and I think you can improve it with this. https://www.postgresql.org/docs/12/runtime-config-query.html#GUC-PLAN-CACHE_MODE |plan_cache_mode (enum) | Prepared statements (either explicitly prepared or implicitly generated, for example by PL/pgSQL) can be executed using custom or generic plans. Custom plans are made afresh for each execution using its specific set of parameter values, while generic plans do not rely on the parameter values and can be re-used across executions. Thus, use of a generic plan saves planning time, but if the ideal plan depends strongly on the parameter values then a generic plan may be inefficient. The choice between these options is normally made automatically, but it can be overridden with plan_cache_mode. The allowed values are auto (the default), force_custom_plan and force_generic_plan. This setting is considered when a cached plan is to be executed, not when it is prepared. For more information see PREPARE. -- Justin ------sinikael-?=_1-16201200931320.9320682518431689 Content-Type: text/html; format=flowed Content-Transfer-Encoding: 7bit
Shouldn't this process be automatic based on some heuristics?

Saving 10ms planning but costing 14s execution is catastrophic.

For example, using some statistics to limit planner time to some percent of of previous executions. 
This way, if query is fast, planning is fast, but if query is slow, more planning can save huge execution time.
This is a better general usage option and should be enabled by default, and users who want fast planning should set the variable to use the generic plan.



Justin Pryzby wrote:


On Sun, May 02, 2021 at 07:45:26PM +0000, Alex wrote:

PreparedStatement: 15s
Raw query with embedded params: 1s
See issue on github with query and explain analyze:


| ..PostgreSQL Version?  12
|Prepared statement
|...
|Planning Time: 11.596 ms
|Execution Time: 14799.266 ms
|
|Raw statement
|Planning Time: 22.685 ms
|Execution Time: 1012.992 ms

The prepared statemnt has 2x faster planning time, which is what it's meant to
improve.

The execution time is slower, and I think you can improve it with this.
|plan_cache_mode (enum)
|    Prepared statements (either explicitly prepared or implicitly generated, for example by PL/pgSQL) can be executed using custom or generic plans. Custom plans are made afresh for each execution using its specific set of parameter values, while generic plans do not rely on the parameter values and can be re-used across executions. Thus, use of a generic plan saves planning time, but if the ideal plan depends strongly on the parameter values then a generic plan may be inefficient. The choice between these options is normally made automatically, but it can be overridden with plan_cache_mode. The allowed values are auto (the default), force_custom_plan and force_generic_plan. This setting is considered when a cached plan is to be executed, not when it is prepared. For more information see PREPARE.

--
Justin
------sinikael-?=_1-16201200931320.9320682518431689--