[pgpool-general: 9460] Re: Clarification on query results cache visibility
Achilleas Mantzios
a.mantzios at cloud.gatewaynet.com
Sat May 3 17:55:29 JST 2025
Good day Tatsuo
On 3/5/25 09:21, Tatsuo Ishii wrote:
>> On 3/5/25 03:41, Tatsuo Ishii wrote:
>>> Dear Achilleas,
>>>
>>> Thank you for the report and logs. I will look into them. BTW, Can I
>>> assume that you did below with patch?
>> Thank you, yes with the second patch.
> So, with no patch (stock 4.6.0) it works with or without
> prepareThreshold=0?
Yes, with the stock 4.6.0 it works for this scenario, no matter the
prepareThreshold setting, I run this twice, one with prepareThreshold=0
and then prepareThreshold=5, no problem with this set of queries.
So, without the patch, we have the first problem of the update as shown
on test PgPoolTest.java :
SELECT app, urlext FROM testpgpool WHERE username = ? AND app IN
('performreport') AND detail = ''
which kept using the cache improperly because previous update did not
invalidate, and you solved it with 2 different patches, however this
second patch (I dont know about the first) introduced this new bug.
I will try with the first patch applied and let you know ASAP.
>
>>> Best regards,
>>> --
>>> Tatsuo Ishii
>>> SRA OSS K.K.
>>> English:http://www.sraoss.co.jp/index_en/
>>> Japanese:http://www.sraoss.co.jp
>>>
>>>> Dear Tatsuo I was not able to replicate the problem, lots of queries
>>>> lots of tables involved to make it identical.
>>>>
>>>> I wrote a test but no success in making the problem happen.
>>>>
>>>> On all the below I use
>>>>
>>>> parents[1]=?
>>>>
>>>> instead of
>>>>
>>>> first(parents)=?
>>>>
>>>> to eliminate exotic factors.
>>>>
>>>> At least I observed that for some reason , setting in java :
>>>> prepareThreshold = 0, which means use only unnamed statements,
>>>> consistently gives correct results .
>>>>
>>>> But there is clearly a problem :
>>>>
>>>> an insertion happens in machdefs table and a subsequent select fetches
>>>> from memory cache. So I attach to you full logs of both pgsql and
>>>> pgpool for both runs, one with prepareThreshold=5 (problem) and one
>>>> with prepareThreshold=0 (no problem).
>>>>
>>>>
>>>> Since in pgpool log there is no way to get the values of the
>>>> parameters in Bind and Execute (whereas in pgsql this is possible) , I
>>>> was only "joining" the two log files by the exact timestamp . My
>>>> observations, regarding the problematic run are :
>>>>
>>>> on pgpool
>>>>
>>>> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacomline:2743LOG:
>>>> Parse message from frontend.
>>>> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacom
>>>> line:2744DETAIL: statement: "", query: "select defid from machdefs
>>>> where parents[1]=$1 order by description,partid"
>>>> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacomline:2745LOG:
>>>> DB node id: 0 backend pid: 59852 statement: Parse: select defid from
>>>> machdefs where parents[1]=$1 order by description,partid
>>>> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacomline:2746LOG:
>>>> Bind message from frontend.
>>>> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacom
>>>> line:2747DETAIL: portal: "", statement: ""
>>>> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacomline:2748LOG:
>>>> DB node id: 0 backend pid: 59852 statement: Bind: select defid from
>>>> machdefs where parents[1]=$1 order by description,partid
>>>> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacomline:2749LOG:
>>>> Describe message from frontend.
>>>> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacom
>>>> line:2750DETAIL: portal: ""
>>>> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacomline:2751LOG:
>>>> DB node id: 0 backend pid: 59852 statement: D message
>>>> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacomline:2752LOG:
>>>> Execute message from frontend.
>>>> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacom
>>>> line:2753DETAIL: portal: ""
>>>> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacomline:2754LOG:
>>>> statement: select defid from machdefs where parents[1]=$1 order by
>>>> description,partid
>>>> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacomline:2755LOG:
>>>> fetch from memory cache
>>>> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacom
>>>> line:2756DETAIL: query result fetched from cache. statement: select
>>>> defid from machdefs where parents[1]=$1 order by description,partid
>>>> 0001000100010
>>>> 00000040CCD179D0000
>>>>
>>>> on pgsql
>>>>
>>>> 127.0.0.1(15112) [59852] 6814a7ed.e9cc 2025-05-02 14:10:47.582 EEST
>>>> SMA amantzio at dynacomline:1340 LOG: duration: 0.042 ms parse
>>>> <unnamed>: select defid from machdefs where parents[1]=$1 order by
>>>> description,partid
>>>> 127.0.0.1(15112) [59852] 6814a7ed.e9cc 2025-05-02 14:10:47.582 EEST
>>>> SMA amantzio at dynacomline:1341 LOG: duration: 0.070 ms bind
>>>> <unnamed>: select defid from machdefs where parents[1]=$1 order by
>>>> description,partid
>>>> 127.0.0.1(15112) [59852] 6814a7ed.e9cc 2025-05-02 14:10:47.582 EEST
>>>> SMA amantzio at dynacomline:1342 DETAIL: Parameters: $1 = '214767517'
>>>>
>>>> (no execute)
>>>>
>>>> ---
>>>>
>>>> the problem is manifested here :
>>>> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacomline:2755LOG:
>>>> fetch from memory cache
>>>> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacom
>>>> line:2756DETAIL: query result fetched from cache. statement: select
>>>> defid from machdefs where parents[1]=$1 order by description,partid
>>>> 0001000100010
>>>> 00000040CCD179D0000
>>>>
>>>> because earlier he have :
>>>> [59728] 2025-05-02 14:10:45.038 SMA amantzio at dynacomline:2613LOG:
>>>> DB node id: 0 backend pid: 59852 statement: Execute: insert into
>>>> machdefs(description,partid,machtypeid,rhbec,rhdue,periodbec,perioddue,p
>>>> arents,specialper,action,application,pms_importance, pms_risk,
>>>> actionnote , jobnote) values($1,$2,$3,$4,$5,$6,$7,(SELECT
>>>> intarray_push_array(itoar($8),coalesce((select parents from machdefs
>>>> where defid=$9),'{
>>>> }'::integer[]))),$10,$11,$12,$13, $14,$15,$16)
>>>>
>>>> this insertion should have invalidated the cache for this query :
>>>> select defid from machdefs where parents[1]=$1 order by
>>>> description,partid
>>>>
>>>> ========================================
>>>>
>>>>
>>>> please have a look, I am so sorry I could not reprooduce by a simple
>>>> program.
>>>>
>>>> (yes I looked on every detail, no luck).
>>>>
>>>>
>>>> On 5/1/25 06:02, Achilleas Mantzios wrote:
>>>>> On 1/5/25 03:02, Tatsuo Ishii wrote:
>>>>>>> update : the bug (this new bug) is not present prior to the first
>>>>>>> patch. So the bug (the new one) is not present in plain vanilla :
>>>>>>> pgpool-II-4.6.0 . Reverting both patches solves the issue with the new
>>>>>>> bug which has most probably to do with an array function called
>>>>>>> "first" :
>>>>>> "first" is coming with the extension? I am not familiar with it.
>>>>> This (and a couple of others I wrote back then) is a C function
>>>>> written by me, when still intarray was not an extension, I mean before
>>>>> the extensions framework, sometime in 2004 or so. This is a simple C
>>>>> function which returns the first element of an array.
>>>>>
>>>>> dynacom=# \df+ first
>>>>> List
>>>>> of functions
>>>>> Schema | Name | Result data type | Argument data types | Type |
>>>>> Volatility | Parallel | Owner | Security | Access privileges
>>>>> | Language | Source code |
>>>>> Description
>>>>> --------+-------+------------------+---------------------+------+------------+----------+----------+----------+--------------------------+----------+-------------+
>>>>> -------------
>>>>> public | first | integer | integer[] | func |
>>>>> immutable | unsafe | postgres | invoker | postgres=X/postgres
>>>>> +| c | first |
>>>>>
>>>>> | | | | |
>>>>> | | | | powerprom=X/postgres
>>>>> +| | |
>>>>>
>>>>> | | | | |
>>>>> | | | | default_group=X/postgres
>>>>> | | |
>>>>>
>>>>> (1 row)
>>>>>
>>>>> dynacom=#
>>>>>
>>>>>
>>>>>>> select defid, description from machdefs where first(parents)=214766150
>>>>>>> order by description;
>>>>>>>
>>>>>>> I haven't been able to reproduce with SQL (from psql).
>>>>>> Is it possible for you to create a java reproducer?
>>>>> I will try.
>>>>>>> Also reverting both patches, i.e. going back to plain vanilla
>>>>>>> pgpool-II-4.6.0 solves this new bug, but re-introduces the previous (
>>>>>>> with seeing stale and data and not invalidate data on table
>>>>>>> testpgpool)
>>>>>>>
>>>>>>>>>>> Best regards,
>>>>>>>>>>> --
>>>>>>>>>>> Tatsuo Ishii
>>>>>>>>>>> SRA OSS K.K.
>>>>>>>>>>> English:http://www.sraoss.co.jp/index_en/
>>>>>>>>>>> Japanese:http://www.sraoss.co.jp
>>>>>>>>>> _______________________________________________
>>>>>>>>>> pgpool-general mailing list
>>>>>>>>>> pgpool-general at pgpool.net
>>>>>>>>>> http://www.pgpool.net/mailman/listinfo/pgpool-general
>>>>>>>>> _______________________________________________
>>>>>>>>> pgpool-general mailing list
>>>>>>>>> pgpool-general at pgpool.net
>>>>>>>>> http://www.pgpool.net/mailman/listinfo/pgpool-general
>>>>>>>> _______________________________________________
>>>>>>>> pgpool-general mailing list
>>>>>>>> pgpool-general at pgpool.net
>>>>>>>> http://www.pgpool.net/mailman/listinfo/pgpool-general
>>>>> _______________________________________________
>>>>> pgpool-general mailing list
>>>>> pgpool-general at pgpool.net
>>>>> http://www.pgpool.net/mailman/listinfo/pgpool-general
>> _______________________________________________
>> pgpool-general mailing list
>> pgpool-general at pgpool.net
>> http://www.pgpool.net/mailman/listinfo/pgpool-general
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.pgpool.net/pipermail/pgpool-general/attachments/20250503/162d1887/attachment-0001.htm>
More information about the pgpool-general
mailing list