[pgpool-general: 9457] Re: Clarification on query results cache visibility
Tatsuo Ishii
ishii at postgresql.org
Sat May 3 09:41:27 JST 2025
Dear Achilleas,
Thank you for the report and logs. I will look into them. BTW, Can I
assume that you did below with patch?
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 dynacom line: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 dynacom line: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 dynacom line: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 dynacom line: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 dynacom line: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 dynacom line:2751LOG:
> DB node id: 0 backend pid: 59852 statement: D message
> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacom line: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 dynacom line: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 dynacom line: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 dynacom line: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 dynacom line: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 dynacom line:1342 DETAIL: Parameters: $1 = '214767517'
>
> (no execute)
>
> ---
>
> the problem is manifested here :
> [59728] 2025-05-02 14:10:47.582 SMA amantzio at dynacom line: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 dynacom line: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
More information about the pgpool-general
mailing list