To check if a bucket has expired, a comparison of the time elapsed
since last bucket change was being done in get_next_wbucket() function
using the following line:
while ((current_usec - current_bucket_usec) > (PGSM_BUCKET_TIME
* 1000 * 1000))
The problem is that the expression compares a uint64 (current_usec)
with a int32 (PGSM_BUCKET_TIME), if a given user configures a value for
pgsm_bucket_time GUC (let's call it T) that could overflow int32 range
in the expression T*1000*1000 > 2**31-1, then the result would be a
negative integer cast to (uint64), resulting in a large uint64 value that
would evaluate the expression as false, thus never updating bucket
number.
When querying pg_stat_monitor view, for every entry it's verified if
the entry has not yet expired by calling IsBucketValid(bucket_number).
Using the entry's bucket number the function calculates if the time
since the bucket started, using shared global variable
pgss->bucket_start_time[bucket_id], is still valid.
Since pgss->bucket_start_time is not properly initialized in
get_next_wbucket(), the function IsBucketValid() will always
return false, thus not listing any entries in the view.
After fixing the problem with utility statements, this whole block:
do $$
declare
n integer:= 1;
begin
loop
PERFORM a,b,c,d FROM t1, t2, t3, t4
WHERE t1.a = t2.b AND t3.c = t4.d ORDER BY a;
exit when n = 1000;
n := n + 1;
end loop;
end $$;
Is only processed once, as those are nested statements, in order to
match the 1000 statements the GUC pg_stat_monitor.track must be set to
'all' and then back to the default of 'top' when done testing it.
There was a missing increment/decrement to exec_nested_level in
pgss_ProcessUtility hook, due to this, some utility statements could
end up being processed more than once, as PostgreSQL may recurse into
this hook for sub-statements or when processing a query string
containing multiple semicolon-separated statements.
Updated the Forum URL to point to the dedicated
pg_stat_monitor forum in `README.md` and
`CONTRIBUTING.md`, removed link to the Discord
channel to ensure that conversations are focused
to one location. Updated the table of contents in
the README.
Signed-off-by: Lenz Grimmer <lenz.grimmer@percona.com>
This commit adds following three sql based testcases:
1) Test unique application name set by user.
2) Histogram function is working properly as desired.
3) Error on insert is shown with proper message.
After the split into multiple pg_stat_monitor--1.0.XX.sql.in sql files,
where XX is the PostgreSQL version, it was forgotten to add the errors
view to the relevant files, this commit fixes that.
Added a link to pg_stat_monitor view reference in the Overview
Aded PG 14 to supported versions
Updated links in the Documentation section
modified: README.md
If a query exceeds pg_stat_monitor.pgsm_query_max_len, then it's
truncated before we save it into the query buffer (SaveQueryText).
When reading the query back, on pg_stat_monitor_internal, we allocate a
buffer for the query with length = pg_stat_monitor.pgsm_query_max_len,
the problem is that the read_query function adds a '\0' to the end of
the buffer when reading a query, thus if a query has been truncated, for
example, to 1024, when reading it back read_query will store the '\0' at
the position 1025, an out of array bounds position.
Then, when we call pfree to release the buffer, PostgreSQL notices the
buffer overrun and triggers an error assertion, the assertion calls our
error hook which attempts to acquire the shared pgss->lock before
pg_stat_monitor_internal has released it, leading to a deadlock.
To avoid the problem we add 1 more byte to the extra '\0' during palloc
call for query_text and parent_query_text.
Also, we release the lock before calling pfree, just in case PostgreSQL
finds a problem in pfree we won't deadlock again and get the error
reported correctly.
If a backend would change the application name during execution,
pg_stat_monitor would then fail to read the updated value, as it caches
the result in order to avoid calling the expensive functions
pgstat_fetch_stat_numbackends() and pgstat_fetch_stat_local_beentry().
A workaround was found, we can just read an exported GUC from
PostgreSQL backend itself, namely application_name, from utils/guc.h,
thus saving us from having to call those expensive functions.
Updated sql files (pg_stat_monitor_settings view).
Using right variable name and level checking on pgss_store:
key.toplevel = ((exec_nested_level + plan_nested_level) == 0);
The issue with wrong query call count was taking place during transition
to a new bucket, the process is shortly describe bellow:
1. Scan for pending queries in previous bucket.
2. Add pending queries to the new bucket id.
3. Remove pending queries from previous bucket id.
The problem is that when switching to a new bucket, we reset query
statistics for a given entry being processed, so, for example, if the
pending query had a call count of 10 (9 of which were finished, 10th is
the pending one), if we move this query to the new bucket, the entry
will have its stats reseted, clearing the query call count to zero.
To solve the problem, whenever a pending query is detected, if the entry
has a call count > 1, we mark it as finished, and don't remove it from
the previous bucket in order to keep its statistics, then we move just
the pending query (10th in the example) to the new bucket id.
Another issue is that when moving a entry to a new bucket, we missed
copying the query position from the previous entry, which is used to
locate the query text in the query buffer:
hash_entry_dealloc():291
new_entry->query_pos = old_entry->query_pos;
Can't call elog() function from inside the pgsm_log as the pgss_hash
lock could be already acquired in exclusive mode, since elog() triggers
the psmg_emit_log hook, when it calls pgss_store it will try to acquire
the pgss_hash lock again, leading to a deadlock.
As the query normalization and query cleaning is always done in the
right place (pgss_store), no more parsed queries have a trailling comma
';' at the end.
Also, on error regression test, after fixing some problems with utility
related queries, we now have two entries for the RAISE WARNING case, the
first entry is the utility query itself, the second entry is the error
message logged by emit_log_hook.
Some queries have the order adjusted due to the fix introduced by the
previous commits.
This commit introduces serveral improvements:
1. Removal of pgss_store_query and pgss_store_utility functions: To
store a query, we just use pgss_store(), this makes the code more
uniform.
2. Always pass the query length to the pgss_store function using parse
state from PostgreSQL to avoid calculating query length again.
3. Always clean the query (extra spaces, update query location) in
pgss_store.
4. Normalize queries right before adding them to the query buffer, but
only if user asked for query normalization.
5. Correctly handle utility queries among different PostgreSQL versions:
- A word about how utility functions are handled on PG 13 and later
versions:
- On PostgreSQL <= 13, we have to compute a query ID, on later
versions we can call EnableQueryId() to inform Postmaster we
want to enable query ID computation.
- On PostgreSQL <= 13, post_parse hook is called after process
utility hook, on PostgreSQL >= 14, post_parse hook is called
before process utility functions.
- Based on that information, on PostgreSQL <= 13 / process utility,
we pass 0 as queryid to the pgss_store function, then we calculate a
queryid after cleaning the query (CleanQueryText) using
pgss_hash_string.
- On PostgreSQL 14 onward, post_parse() is called before
pgss_ProcessUtility, we Clear queryId for prepared statements
related utility, on process utility hook, we save the query ID for
passing it to the pgss_store function, but mark the query ID with
zero to avoid instrumenting it again on executor hooks.
After couple CPU profiling sessions with perf, it was detected that the
function pgstat_fetch_stat_numbackends() is very expensive, reading the
implementation on PostgreSQL's backend_status.c just confirmed that.
We use that function on pg_stat_monitor to retrieve the application name
and IP address of the client, we now cache the results in order to avoid
calling it for every query being processed.
If pgsm_overflow_target is ON (default, 1) and the query buffer
overflows, we now dump the buffer and keep track of how many times
pg_stat_monitor changed bucket since that.
If an overflow happen again before pg_stat_monitor cycle through
pgsm_max_buckets buckets (default 10), then we don't dump the buffer
again, but instead report an error, this ensures that only one dump file
of size pgsm_query_shared_buffer will be in disk at any time, avoiding
slowing down queries to the pg_stat_monitor view.
As soon as pg_stat_monitor cycles through all buckets, we remove the
dump file and reset the counter (pgss->n_bucket_cycles).
pgss_ExecutorEnd: Avoid unnecessary memset(plan_info, 0, ...).
We only use this object if the condition below is true, in which case we
already initialize all the fields in the object, also we now store the
plan string length (plan_info.plan_len) to avoid calling strlen on it
again later:
if (queryDesc->operation == CMD_SELECT && PGSM_QUERY_PLAN) {
... here we initialize plan_info
If the condition is false, then we pass a NULL PlanInfo* to the
pgss_store to avoid more unnecessary processing.
pgss_planner_hook: Similar, avoid memset(plan_info, 0, ...) this object
is not used here, so we pass NULL to pgss_store.
pg_get_application_name: Remove call to strlen, snprintf already give us
the calculated string length, so we just return it.
pg_get_client_addr: Cache localhost, avoid calling
ntohl(inet_addr("127.0.0.1")) all the time.
pgss_update_entry: Make use of PlanInfo->plan_len, avoiding a call to
strlen again.
intarray_get_datum: Init the string by setting the first byte to '\0'.
The memory area reserved for query text (pgsm_query_shared_buffer) was
divided evenly for each bucket, this allowed to have the same query,
e.g. "SELECT 1", duplicated in different buckets, thus wasting space.
This commit fix the query text duplication by adding a new hash table
whose only purpose is to verify if a given query is already added to the
buffer (by using the queryID).
This allows different buckets that share the same query to point to a
unique entry in the query buffer (pgss_qbuf).
When pg_stat_monitor moves to a new bucket id, by avoiding adding a
query that already exists in the buffer it can also save some CPU time.
There were couple issues to handle, the main one was that our log hook
(pgsm_emit_log_hook) was being called after the shared memory hook
completed (pgss_shmem_startup) but before PostgreSQL boostraping code
finished, thus triggering the following assertion during a call to
LWLockAcquire():
Assert(!(proc == NULL && IsUnderPostmaster));
proc is a pointer to MyProc, a PostgreSQL's shared global variable that
was not yet initalized by PostgreSQL.
We must also check for a NULL pointer return in pg_get_backend_status()
the pgstat_fetch_stat_local_beentry() function may return a NULL pointer
during initialization, in which case we use "127.0.0.1" for the client
address, and "postmaster" for application name.
Hamid Akhtar
Ibrar Ahmed
Diego Fronza
Anastasia Alexadrova
Lenz Grimmer
Naeem Akhter
Vadim Yalovets
Umair Shahid
Evgeniy Patlan