[pgpool-general: 9443] Re: Clarification on query results cache visibility
Achilleas Mantzios
a.mantzios at cloud.gatewaynet.com
Tue Apr 29 05:26:39 JST 2025
Dear Tatsuo
here is a simple java program that exhibits it all . I attach it. Also I
attach the class for you to be able to run it more easily.
no inheritance, no schema magic needed. It works on the very single table .
amantzio@[local]/dynacom=# \d testpgpool
Table "public.testpgpool"
Column | Type | Collation | Nullable | Default
----------+------------------------+-----------+----------+---------
username | character varying(200) | | not null |
app | text | | not null |
detail | text | | not null |
urlext | text | | not null |
Indexes:
"testpgpool_pkey" PRIMARY KEY, btree (username, app, detail)
place the class inside a dir named : test like :
achix at achix-xps159550:~/eclipse-workspace/PgPoolTest/bin$ pwd
/home/achix/eclipse-workspace/PgPoolTest/bin
achix at achix-xps159550:~/eclipse-workspace/PgPoolTest/bin$ ls
test
achix at achix-xps159550:~/eclipse-workspace/PgPoolTest/bin$ ls test/
PgPoolTest.class
achix at achix-xps159550:~/eclipse-workspace/PgPoolTest/bin$
then run it from the current dir (the one how contains dir test) as :
java -cp ".:/home/achix/Downloads/postgresql-42.7.5.jar" test.PgPoolTest
<your_pgpool_host> <your_pgpool_port> <your_db_name> user password
as it runs (and you can see clearly that it does not append z1 in every
run as it should), please go to a shell and type :
/usr/local/pgpool/bin/pcp_invalidate_query_cache
you will now see the last real data read (with the
perfurlext=?groupno=yesz1)
and giving pcp_invalidate_query_cache again, will cause the program to
yield : perfurlext=?groupno=yesz1z1 and so forth.
On 28/4/25 10:58, Achilleas Mantzios - cloud wrote:
>
> Good Day Tatsuo
>
> I have not been able to reproduce via sql .
>
> I will provide full log of pgpool as in the app (java) we didn't get
> any useful logs , only entries like :
>
> 2025-04-28 10:07:01,717 WARN
> [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-35)
> SQL Warning Code: 0, SQLState: XX000
> 2025-04-28 10:07:01,717 WARN
> [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-35)
> Parse message from frontend.
> 2025-04-28 10:07:01,717 WARN
> [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-35)
> SQL Warning Code: 0, SQLState: XX000
> 2025-04-28 10:07:01,717 WARN
> [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-35)
> DB node id: 0 backend pid: 34753 statement: Parse: COMMIT
> 2025-04-28 10:07:01,717 WARN
> [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-35)
> SQL Warning Code: 0, SQLState: XX000
> 2025-04-28 10:07:01,717 WARN
> [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-35)
> Bind message from frontend.
> 2025-04-28 10:07:01,717 WARN
> [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-35)
> SQL Warning Code: 0, SQLState: XX000
> 2025-04-28 10:07:01,717 WARN
> [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-35)
> DB node id: 0 backend pid: 34753 statement: Bind: COMMIT
> 2025-04-28 10:07:01,717 WARN
> [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-35)
> SQL Warning Code: 0, SQLState: XX000
> 2025-04-28 10:07:01,717 WARN
> [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-35)
> Execute message from frontend.
> 2025-04-28 10:07:01,717 WARN
> [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-35)
> SQL Warning Code: 0, SQLState: XX000
> 2025-04-28 10:07:01,717 WARN
> [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-35)
> DB node id: 0 backend pid: 34753 statement: Execute: COMMIT
> 2025-04-28 10:07:01,717 WARN
> [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-35)
> SQL Warning Code: 0, SQLState: XX000
>
> which do not seem to contain any useful info.
>
> Please disregard any noise in the logs, we are interested on useroptions .
>
> The scenario goes like :
>
> 1) Front page queries the db for a specific useroption for a subapp
> (saved from a previous click from within that app, we will look into
> this later in step 2).
>
> The prepared stmt is :
>
> SELECT app, urlext FROM useroptions WHERE username = ? AND app IN
> ('status', 'performreport', 'freshwater', 'comms') AND detail = '';
>
> User name in our tests will be 'Achilleas Mantzios'
>
> The front page uses this result to build the url for the Performance
> Report subapp .
>
> 2) Then the user clicks into the Performance Report subapp , and makes
> some clicks / selections which the app tries to store in useroptions.
> It does so by investigating if there is any option already stored or
> not. By issuing prep stmt:
>
> select 1 from useroptions where username=? and app='performreport' and
> detail=''
>
> From the result it decides whether to insert or update (back then
> there was no upsert so the app stayed that way), and stores the users
> selections inside the app, depending on the result from the above
> select by either :
>
> insert into useroptions(username,app,detail,urlext)
> values('"+username+"','performreport','',?)
>
> or
>
> update useroptions set urlext=? where username='"+username+"' and
> app='performreport' and detail=''
>
> 3) then by visiting the front page again, (like in1) the front page
> queries
>
> SELECT app, urlext FROM useroptions WHERE username = ? AND app IN
> ('status', 'performreport', 'freshwater', 'comms') AND detail = '';
>
> and presents the new saved options to the Performance Report subapp .
>
> The problem that my colleague found is that while in 2) and making a
> selection, although being stored correctly in the DB, however, by
> clicking on the home page again, the user sees the initially fetched
> result and not the just updated one.
>
> Now I will present the actual test scenario pgpool log and some
> queries from psql :
>
> Initially we have , straight from the db
>
> achill at smadevnu:~ % psql
> psql (17.4)
> Type "help" for help.
>
> amantzio@[local]/dynacom=# SET application_name to 'SMA ';select
> set_search_path('bdynacom,epaybdynacom,epay');
> SET
> set_search_path
> -----------------
>
> (1 row)
>
> amantzio@[local]/dynacom=# select * from useroptions where username =
> 'Achilleas Mantzios';
> username | app | detail | urlext
> --------------------+---------------+--------+----------------------
> Achilleas Mantzios | performreport | | ?group=yes&groupno=7
> (1 row)
>
> amantzio@[local]/dynacom=#
>
> Now I login to the app, via the front page, indeed the url I get for
> this subapp inside the front page is :
>
> https://localhost:8443/sma/pr/perfleet?group=yes&groupno=7
>
> Now I click into the supapp and now choose group 1 :
>
> It correctly stores it in the db :
>
> achill at smadevnu:~ % psql
> psql (17.4)
> Type "help" for help.
>
> amantzio@[local]/dynacom=# SET application_name to 'SMA ';select
> set_search_path('bdynacom,epaybdynacom,epay');
> SET
> set_search_path
> -----------------
>
> (1 row)
>
> amantzio@[local]/dynacom=# select * from useroptions where username =
> 'Achilleas Mantzios';
> username | app | detail | urlext
> --------------------+---------------+--------+----------------------
> Achilleas Mantzios | performreport | | ?group=yes&groupno=1
> (1 row)
>
> amantzio@[local]/dynacom=#
>
> Now I click on the home page , but there I still see the stale initial
> https://localhost:8443/sma/pr/perfleet?group=yes&groupno=7 url !!
>
> From psql I get the correct results , cannot reproduce :
>
> achill at smadevnu:~ % psql -p 9999
> psql (17.4)
> Type "help" for help.
>
> amantzio@[local]/dynacom=# SET application_name to 'SMA ';select
> set_search_path('bdynacom,epaybdynacom,epay');
> LOG: Query message from frontend.
> DETAIL: query: "SET application_name to 'SMA ';"
> LOG: DB node id: 0 backend pid: 35636 statement: SELECT
> pg_catalog.version()
> LOG: DB node id: 0 backend pid: 35636 statement: SET application_name
> to 'SMA ';
> SET
> LOG: Query message from frontend.
> DETAIL: query: "select set_search_path('bdynacom,epaybdynacom,epay');"
> LOG: DB node id: 0 backend pid: 35636 statement: SELECT count(*) FROM
> pg_catalog.pg_proc AS p, pg_catalog.pg_namespace AS n WHERE p.proname
> = 'set_search_path' AND n.oid = p.pronamespace
> AND n.nspname ~ '.*' AND p.provolatile = 'i'
> LOG: DB node id: 0 backend pid: 35636 statement: SELECT count(*) FROM
> pg_catalog.pg_proc AS p, pg_catalog.pg_namespace AS n WHERE p.proname
> = 'set_search_path' AND n.oid = p.pronamespace
> AND n.nspname ~ '.*' AND p.provolatile = 'v'
> LOG: DB node id: 0 backend pid: 35636 statement: select
> set_search_path('bdynacom,epaybdynacom,epay');
> set_search_path
> -----------------
>
> (1 row)
>
> amantzio@[local]/dynacom=# PREPARE foost(text) AS SELECT app, urlext
> FROM useroptions WHERE username = $1 AND app IN ('status',
> 'performreport', 'freshwater', 'comms') AND detail = '';
> LOG: Query message from frontend.
> DETAIL: query: "PREPARE foost(text) AS SELECT app, urlext FROM
> useroptions WHERE username = $1 AND app IN ('status',
> 'performreport', 'freshwater', 'comms') AND detail = '';"
> LOG: DB node id: 0 backend pid: 35636 statement: PREPARE foost(text)
> AS SELECT app, urlext FROM useroptions WHERE username = $1 AND app IN
> ('status', 'performreport', 'freshwater', 'comm
> s') AND detail = '';
> PREPARE
> amantzio@[local]/dynacom=#
> amantzio@[local]/dynacom=# EXECUTE foost('Achilleas Mantzios');
> LOG: Query message from frontend.
> DETAIL: query: "EXECUTE foost('Achilleas Mantzios');"
> LOG: DB node id: 0 backend pid: 35636 statement: EXECUTE
> foost('Achilleas Mantzios');
> app | urlext
> ---------------+----------------------
> performreport | ?group=yes&groupno=1
> (1 row)
>
> amantzio@[local]/dynacom=# SELECT app, urlext FROM useroptions WHERE
> username = 'Achilleas Mantzios' AND app IN ('status',
> 'performreport', 'freshwater', 'comms') AND detail = '';
> LOG: Query message from frontend.
> DETAIL: query: "SELECT app, urlext FROM useroptions WHERE username =
> 'Achilleas Mantzios' AND app IN ('status', 'performreport',
> 'freshwater', 'comms') AND detail = '';"
> app | urlext
> ---------------+----------------------
> performreport | ?group=yes&groupno=1
> (1 row)
>
> LOG: fetch from memory cache
> DETAIL: query result fetched from cache. statement: SELECT app,
> urlext FROM useroptions WHERE username = 'Achilleas Mantzios' AND app
> IN ('status', 'performreport', 'freshwater', 'comms'
> ) AND detail = '';
> amantzio@[local]/dynacom=#
>
> More clicks on the front page , still the old reslut :
> ?group=yes&groupno=7
>
> I supply the full pgpool log. Please specify if we can do anything more.
>
>
> _______________________________________________
> 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/20250428/65877484/attachment-0001.htm>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: PgPoolTest.java
Type: text/x-java
Size: 3298 bytes
Desc: not available
URL: <http://www.pgpool.net/pipermail/pgpool-general/attachments/20250428/65877484/attachment-0002.bin>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: PgPoolTest.class
Type: application/x-java
Size: 4197 bytes
Desc: not available
URL: <http://www.pgpool.net/pipermail/pgpool-general/attachments/20250428/65877484/attachment-0003.bin>
More information about the pgpool-general
mailing list