[pgpool-general: 9441] Re: Clarification on query results cache visibility
Achilleas Mantzios - cloud
a.mantzios at cloud.gatewaynet.com
Mon Apr 28 16:58:58 JST 2025
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.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.pgpool.net/pipermail/pgpool-general/attachments/20250428/edb20e2d/attachment-0001.htm>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: pgpool-2025-04-28.log
Type: text/x-log
Size: 960467 bytes
Desc: not available
URL: <http://www.pgpool.net/pipermail/pgpool-general/attachments/20250428/edb20e2d/attachment-0001.bin>
More information about the pgpool-general
mailing list