[pgpool-general: 9436] Re: Clarification on query results cache visibility

[Tatsuo Ishii]

>>> I'm confused. So the search_path is literary always constant (not
>>> something like '$user,public'), or the search_path is changed by
>>> set_search_path?
>>
>> the app (wildfly) has this in the conf :
>>
>> <new-connection-sql>SET application_name to 'SMA ';select
>> set_search_path('bdynacom,epaybdynacom,epay');</new-connection-sql>
>>
>> This function does some logic and then sets the search path: so by
>> calling it with the above argument values it yields :
>> anonym,bdynacom,epaybdynacom,epay,"$user", public
>>
>> So the potentially relevant schemata here are  the ones that contain
>> our tables  useroptions : bdynacom and public.
>>
>> The above is called at the start of the connection, only. No search
>> path setting in the code. We base our multi-tenancy on this technique
>> to be more precise, so every tenant application sets its own search
>> path, but only once at the start of the connection. So all insertions
>> and selects and updates happen on the unqualified table : useroptions,
>> which is bdynacom.useroptions.

Ok, the search_path is set by the app and only bdynacom and public
include useroptions table.

>> *The problem was discovered inside the same app, with same
>> *search_path,  with the same user, it inserted the new value, but could
>> *not read it. We were unable to reproduce this with plain SQL.*

That's unfortunatete.

>> So we may need to try to reproduce it with java and send you the full
>> working bug. Would you like us to to do this?

No, I am not familiar with Java applications.

> From the tests I am doing today, I am very confident that this hasn't
> got to do with search_path.
> 
> It is like it created a "hidden" cache entry that is only surfacing
> under some conditions.
> 
> Please look :

How did you set search_path? According to the explanation above, the
search_path was set by Java app.

> straight to pgsql :
> 
> achill at smadevnu:~ % psql -U amantzio

Maybe you forgot to copy database name here? I am asking because if
the database name is missing, psql will connect to "amantzio"
database, which is different database from the pgpool session.

> psql (17.4)
> Type "help" for help.
> 
> amantzio@[local]/dynacom=# SELECT tableoid::regclass, app, urlext FROM
> useroptions WHERE username = 'Achilleas
> Mantzios' AND app IN ('performreport') AND detail = '';
>       tableoid       |      app      |        urlext
> ----------------------+---------------+----------------------
> bdynacom.useroptions | performreport | *?group=yes&groupno=7 <-- real
> value*
> (1 row)
> 
> marked as bold above is the correct value (real value).

Ok.

> 1st pgpool session :
> 
> achill at smadevnu:~ % psql -p 9999 -U amantzio dynacom
> psql (17.4)
> Type "help" for help.
> 
> amantzio@[local]/dynacom=# SELECT app, urlext FROM useroptions WHERE
> username = 'Achilleas Mantzios' AND app IN ('performreport') AND d
> etail = '';
>      app      |        urlext
> ---------------+----------------------
> performreport | *?group=yes&groupno=2  <-- old value*
> (1 row)

Before starting the query, can you set below?
pgpool set log_per_node_statement = on;
pgpool set client_min_messages = log;

(you can also set these in pgpool.conf as:
log_per_node_statement = on
set client_min_messages = log)

These will print the query sent to backend and print whether the query
result was fetched from query cache. This will help to know whether
pgpool retrieves the data from query cache or not.

At this point I guess the reason you see the old value could be, the
query cache entry was not removed by previous update for some reasons.
When a SELECT is executed and a query cache entry is created, pgpool
creates a file containing the cache information. This is used to
invalidate cache when the table is updated. If the file is created,
you can see it as: logdir/oid_of_database/oid_of_table. ("logdir" is
set in pgpool.conf).  In this case oid_of_database = oid of dynacom,
and oid_of_table = oid of bdynacom.useroptions. Can you confirm?

> amantzio@[local]/dynacom=# SELECT tableoid::regclass, app, urlext FROM
> useroptions WHERE username = 'Achilleas Mantzios' AND app IN ('p
> erformreport') AND detail = '';
>       tableoid       |      app      |  urlext
> ----------------------+---------------+-----------
> bdynacom.useroptions | performreport | *?group=no  <-- also old value*
> (1 row)
> 
> bow besides the false stale value ( *?group=yes&groupno=2 ) *if we add
> tableoid in the select we also get another also false and stale value
> : "group=no"
> 
> 2nd pgpool session
> 
> pgpool at smadevnu:~ % psql -p 9999 -U amantzio dynacom
> psql (15.7, server 17.4)
> WARNING: psql major version 15, server major version 17.
>         Some psql features might not work.
> Type "help" for help.
> 
> dynacom=# SELECT app, urlext FROM useroptions WHERE username =
> 'Achilleas Mantzios' AND app IN ('performreport
> ') AND detail = '';
>      app      |        urlext
> ---------------+----------------------
> performreport | *?group=yes&groupno=2*
> (1 row)
> 
> dynacom=# /*NO QUERY CACHE*/ SELECT app, urlext FROM useroptions WHERE
> username = 'Achilleas Mantzios' AND app
> IN ('performreport') AND detail = '';
>      app      |        urlext
> ---------------+----------------------
> performreport | *?group=yes&groupno=7    <---- real value*
> (1 row)
> 
> dynacom=# /*FORCE QUERY CACHE*/ SELECT app, urlext FROM useroptions
> WHERE username = 'Achilleas Mantzios' AND
> app IN ('performreport') AND detail = '';
>      app      |  urlext
> ---------------+-----------
> performreport | *?group=no  <-- also old value*
> (1 row)
> 
> In the first select we get the same old version  as in the 1st
> session, in the second select (no query cache) we get the real correct
> value , while in the last select by forcing query cache, we get the
> same value as if putting the tableoid in the select.
> 
> 
> now comes the ultra crazy part :
> 
> same session :
> 
> dynacom=# SELECT tableoid::regclass,app, urlext FROM useroptions WHERE
> username = 'Achilleas Mantzios' AND app
> IN ('performreport') AND detail = '';
>       tableoid       |      app      |        urlext
> ----------------------+---------------+----------------------
> bdynacom.useroptions | performreport | ?group=yes&groupno=7
> (1 row)
> 
> dynacom=# SELECT tableoid::regclass, app, urlext FROM useroptions
> WHERE username = 'Achilleas Mantzios' AND ap
> p IN ('performreport') AND detail = '';
>       tableoid       |      app      |  urlext
> ----------------------+---------------+-----------
> bdynacom.useroptions | performreport | ?group=no
> (1 row)
> 
> can you spot the difference ? it is the space after "regclass," here :
> tableoid::regclass, app
> 
> here without the tableoid :
> 
> dynacom=# SELECT app, urlext FROM useroptions WHERE username =
> 'Achilleas Mantzios' AND app IN ('performreport
> ') AND detail = '';
>      app      |        urlext
> ---------------+----------------------
> performreport | ?group=yes&groupno=2
> (1 row)
> 
> dynacom=# SELECT app,urlext FROM useroptions WHERE username =
> 'Achilleas Mantzios' AND app IN ('performreport'
> ) AND detail = '';
>      app      |        urlext
> ---------------+----------------------
> performreport | ?group=yes&groupno=7
> (1 row)
> 
> only different thing is the space in the select ,

That's an expected behavior. When pgpool fetches a cache entry, it is
based on the exact string match of the query strings. So even a white
space matters.

Best regards,
--
Tatsuo Ishii
SRA OSS K.K.
English: http://www.sraoss.co.jp/index_en/
Japanese:http://www.sraoss.co.jp