[GSoC'23] Query Cache

[SudeepRed]

Hi everyone👋🏻
I'm Sudeep Reddy, super glad to be selected as a GSoC'23 contributor for PostgreSQL.
I would be working on adding query caching functionality to pgagroal. This project will be focused more on RnD, trying different variations and testing the implementation. I hope by the end we are successfully able to have this functionality 🤞🏻 !
There are 2 main strategies I have in mind to implement this

1. Using xmin values, to invalidate the cache
2. Relying solely on query parsing, and having cache timeouts

Here is my proposal, which goes deeper into the proposed ideas.
Please feel free to propose new ideas, ask questions and give feedback on my proposal!!

Final Outcome

After experimenting with various caching approaches, we have concluded that it would be more beneficial to operate pgagroal without a cache #376 (reply in thread).
Initially, the idea behind implementing a query cache was to reduce the database load in order to increase the number of transactions per second #58.
However, it became evident that caching had a negative impact on performance, as demonstrated by the graphs below.
All the tests were conducted in release mode and in session pipeline.

pgbench cmd used: pgbench -S -M simple -c X -j X

All the work done is in this PR: #377.

Learnings

This project involved a substantial amount of debugging, particularly in addressing deadlocks and race conditions. I managed to get the basic caching API working by the time of the midterms. However, integrating it with the session pipeline proved to be quite challenging, leading to several issues:

1. Initially, memory leaks were a persistent problem, and I began addressing them through debugging with tools like Valgrind.
   1.1 [GSoC'23] Query Cache #376 (comment)
   1.2 [GSoC'23] Query Cache #376 (comment)
2. Later on, I discovered that string keys needed to be NULL-TERMINATED in uthash; otherwise, the behavior was unpredictable.
   2.1 https://groups.google.com/g/uthash/c/giaBpGoIoLU/m/xL7Vmf91oEsJ
3. Despite these efforts, the memory leak issues remained unresolved. Consequently, we decided to pivot towards a simpler O(n) linear search cache.
   3.1 [GSoC'23] Query Cache #376 (reply in thread).
4. Even with the new approach, memory leak problems persisted. It was eventually determined that initializing these caches in a shared memory segment was the source of the issue. As a solution, we opted for a local memory segment for the cache, and this allowed the linear search cache to function correctly.
   4.1 [GSoC'23] Query Cache #376 (comment) .
5. However, the issues with uthash were still not resolved. To address this, we made changes to the cache entry struct, opting for a char array instead of a pointer. This adjustment successfully resolved all the problems related to uthash.
   5.1 [GSoC'23] Query Cache #376 (comment).

Conclusion and Future Work

Given the cache's poor performance, even with a small 'key' sample size, I am uncertain about how to enhance its functionality.

One important consideration to note is that these tests were conducted on a single machine, where both the database and pgagroal were running on the same system. The cache may potentially offer benefits in scenarios where communication with the database occurs over a network, but I have serious doubts regarding its effectiveness in such cases.

[jesperpedersen]

👍

[solokyo]

Hi, Sudeep

Trade-offs

The two approaches have trade-offs to consider.
Querying DB for xmin values to validate the cache for each incoming query, whether it is cached or not, might be resource heavy. but if we use the second approach, there might be updates in DB outside of the connection pool, and hence we may get stale data when querying. To mitigate this, we would have to set the cache expiry very low, but this would again increase the load on the DB since cache hits would be decreased.

Do you mean you will do either idea 1 or 2? I think we might need to combine idea 1 and 2.

Idea 1 query xmin to the database to check if cached data is still up-to-date.

Idea 2 parse the SQL can be used in several ways:

1. check if the query is cacheable cause SELECTs might include non immutable functions or temp tables.
2. drop the cache data based on TABLE_NAME if the SQL is an UPDATE

[SudeepRed]

Hi @solokyo

Do you mean you will do either idea 1 or 2?

No. I would be implementing both approaches and after testing them using pgbench, we would then decide what to keep. Or maybe we can leave it up to the user.

I think we might need to combine idea 1 and 2.

How do you suggest we combine the two? Since both approaches are very different, I don't see how we can combine those two. Querying xmin values might be resource heavy (we have to test this approach to validate this). Also, if we go with approach 2, it there will be cases where we might fetch stale data, and to mitigate this, we would have to keep the expiration very low. But if the user has a DB where he isn't expecting a lot of writes, then this approach (Idea2) would be very light and efficient. Therefore I would like to leave it up to the user to choose what type of caching he wants.

Idea 2 parse the SQL can be used in several ways:

check if the query is cacheable cause SELECTs might include non immutable functions or temp tables.
drop the cache data based on TABLE_NAME if the SQL is an UPDATE

Yup this is exactly what I would be doing. It needs to be handled with extreme caution, with invalidation being the default course of action. Any volatile functions shouldn't be cacheable (like random() and similar routines).

[solokyo]

Any volatile functions shouldn't be cacheable (like random() and similar routines).

Yes, I was thinking about this. That make sense if we don't cache them at all.

[jesperpedersen]

Yeah, and that is the tricky part of SELECT

[SudeepRed]

Hi @jesperpedersen
I am thinking of tackling the query parsing first. Basically, how we would be extracting the table names, type of query (UPDATE/DELETE/INSERT) and function names from the incoming query string.
Currently, I am trying to figure out how parsers in pgpool2 work. Maybe we can use the same in pgagroal, what do you think?

[jesperpedersen]

@SudeepRed I don't there is anything out there that fits our requirements - shared memory based with atomic locking; feel free to look, but it should be available in standard Linux / *BSD distributions.

[SudeepRed]

I looked around a bit and found that Memcached is very popular.
So wrt atomic locking, maybe we can have a key that would be required before performing any cache operation. Does this sound ok?

[jesperpedersen]

I think going over the wire is a non-starter. We don't want the overhead of network traffic in this path.

[SudeepRed]

Understood. So what about uthash? It provides a way to use hashtables in C.

[jesperpedersen]

You can likely get ideas from it, but for shared cache to work you will need a data structure that is backed by shared memory that can be accessed from all processes

[SudeepRed]

Hii @jesperpedersen , So here is how I plan to implement the caching system. I would be using uthash as the hashtable.
So the structure for the cache would look like this, similar to prometheus_cache

struct query_cache
{
   atomic_schar lock;    /**< lock to protect the cache */
   size_t size;          /**< size of the hashtable */   
   struct hashTable *table;         
} 
struct hashTable {
    string key;    // this would be the SQL query
    int latest_xmin;    // to invalidate the cache
    string data;  // this would be the Query Response
    UT_hash_handle hh;
}

If the largest xmin values of a table are less than the one stored in the cache that means that the xmin values must have reset and thus we invalidate this cache. Also if the xmin value has increased we invalidate the cache. Only when the largest xmin value matches should we return the cached response.

We would also be needing few functions, I'm planning on implementing the following:

1. pgagroal_init_query_cache();
2. pgagroal_query_cache_get();
3. pgagroal_query_cache_invalidate();
4. pgagroal_query_cache_update();
5. pgagroal_query_cache_add();
6. pgagroal_query_cache_clear();

We would need both update and add since uthash doesn't check for key uniqueness, we can use the update method when we invalidate the cache and update it with the latest response since we would be sure that the key(query) would be unique. The add method would check for key uniqueness before adding to the hashtable.

[jesperpedersen]

You can def start with uthash, and work from there. I'm a bit unsure how you will handle key management, and memory management in general.

But, the important part for now - and within the next 2 weeks - is to get a prototype up and running so we can start to identify the real issues with having a cache.

It should probably be pgagroal_query_cache_init(); instead

[SudeepRed]

Hii @jesperpedersen I have updated the PR with tests. I have also modified the datatypes for key and data, also update the documentation for each function. Please have a look and let me know if I need to make any changes.
#377

[jesperpedersen]

Just keep going in this direction (both key and data are likely void*).

We need to look at actual numbers using the cache to see if there is a benefit. You can implement the configuration knobs easily, so get those sorted in your next update. Then start to modify the session pipeline such that it uses the cache.

[SudeepRed]

So what are the different configurable parameter one might expect?
I see query_cache_max_size and probably query_cache_max_entries as 2 possible parameters.
Also I would need to implement some sort of algo (im thinking LRU) for removing older cache entries if the memory overflows. Do you have any other suggestions?

[jesperpedersen]

Yeah, just go with these 2 for now -- query_cache_max_size is the maximum for a cached response, and query_cache_max_entries is the maximum of cache entries.

Yes, there should be LRU functionality, or similar.

[SudeepRed]

Hello @jesperpedersen,

I would like your opinion on creating keys for cache entries. Here is the proposed approach

So to my knowledge we can use two types of queries to query the PostgreSQL db, normal queries (Q) and prepared queries (P).
So in prepared queries:

1. We first receive a P message, which contains the prepared query.
2. Next, we receive a B message, which contains the parameter values for the prepared query.

My approach is to create a key struct that includes both the query and the bind parameters, like this:

struct key {
    string query;
    void* bind_parameters;
}

if we get a Q message we store nil in the bind parameters.

Could you please let me know if this approach is valid and provide your feedback on it?

[SudeepRed]

its working perfectly on master

[SudeepRed]

but i have made no changes to the session pipeline, how is it breaking?

[SudeepRed]

ok i ran make again and its working on my branch also, idk what the exact issue was 🤔 . Sorry for the trouble, will keep you posted if it occurs again

[jesperpedersen]

So, sorted ?

[jesperpedersen]

We need to look at it if it happens again

[SudeepRed]

Hi @jesperpedersen , so i have a couple of doubts after going through the session pipeline code, please correct me if my understanding is wrong anywhere

1. in the function session_client i see that we are writing the query 'Q' directly into the server socket (and hence directly querying the DB),
2. similarly in the function session_server i see that we are writing the result of the query 'Q', row description message 'T', directly into the client socket (hence directly returning to the client, and not to the session_client function)

Now how do i define the caching layer? Ideally it should be in the session_client (to stop it from querying the DB), how do i access this row description message in session_client ?

[SudeepRed]

im new to gdb, how do i use it with pgaroal.
gdb -args ./pgagroal -c pgagroal.conf -a pgagroal_hba.conf -t , is this correct?

[SudeepRed]

idk if its helpful but heres what gdb gives me

(gdb) bt
#0  0x00007ffff7aed42a in epoll_wait (epfd=6, events=0x555555568b60, maxevents=64, timeout=58621) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
#1  0x00007ffff7fa5c3f in ?? () from /lib/x86_64-linux-gnu/libev.so.4
#2  0x00007ffff7fa8693 in ev_run () from /lib/x86_64-linux-gnu/libev.so.4
#3  0x0000555555557fe9 in ev_loop (loop=0x7ffff7fb1720, flags=0) at /usr/include/ev.h:842
#4  0x000055555555b787 in main (argc=6, argv=0x7fffffffdcf8) at /home/devrev-sudeep/pgagroal/src/main.c:1168

[jesperpedersen]

You can use pgagroal_log_message(msg); to check the messages.

You need the query as the key - and the full response as the reply - if either doesn't fit in space allocated, just leave it. To begin with, just get the no operation cache working

[SudeepRed]

Hey jesper!
The following is the output of pgagroal_log_message(msg); (The last msg where my code gets stuck)

540000002100016162616C616E636500000041FF0003000000170004FFFFFFFF
0000440000000B00010000000130430000000D53454C4543542031005A000000
0549
T???!??abalance???A?????????????
??D??????????0C????SELECT 1?Z???
?I

What exactly do you mean by no operation cache working?

Also could you please try to debug this on your end once? Perhaps there's something I'm missing or not implementing correctly. I feel like I've hit a brick wall with debugging this!

[SudeepRed]

Hey Jesper, did you find anything?

[SudeepRed]

hi jesper, so i have implemented global lock, and also the size limits as we discussed over the email. And changed the cache structure to

struct hashEntry
{
   void* value;
   size_t length;
}
struct hashTable
{
   struct hashEntry* key;
   struct hashEntry* data;
}

So the caching mechanism works when i connect it directly to postgresql using psql (yeee progress 🥳 ) and there are no memory leaks in the logic i added.
Now using pgbench i am still facing the same issue and valgrind says that there might be an issue with the HASH_FIND function while adding a cache entry.
here are the logs, any help would be appreciated

==975376== Invalid read of size 8
==975376==    at 0x4C3226A: pgagroal_query_cache_add (query_cache.c:159)
==975376==    by 0x4C1EF54: session_server (pipeline_session.c:574)
==975376==    by 0x4869BC2: ev_invoke_pending (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==975376==    by 0x486DB92: ev_run (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==975376==    by 0x4C46292: ev_loop (ev.h:842)
==975376==    by 0x4C46A77: pgagroal_worker (worker.c:176)
==975376==    by 0x10FED7: accept_main_cb (main.c:1334)
==975376==    by 0x4869BC2: ev_invoke_pending (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==975376==    by 0x486DB92: ev_run (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==975376==    by 0x10BFE8: ev_loop (ev.h:842)
==975376==    by 0x10F786: main (main.c:1168)
==975376==  Address 0x50c64f8 is 5,064 bytes inside an unallocated block of size 4,050,608 in arena "client"
==975376== 
==975376== Invalid read of size 4
==975376==    at 0x4C3226E: pgagroal_query_cache_add (query_cache.c:159)
==975376==    by 0x4C1EF54: session_server (pipeline_session.c:574)
==975376==    by 0x4869BC2: ev_invoke_pending (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==975376==    by 0x486DB92: ev_run (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==975376==    by 0x4C46292: ev_loop (ev.h:842)
==975376==    by 0x4C46A77: pgagroal_worker (worker.c:176)
==975376==    by 0x10FED7: accept_main_cb (main.c:1334)
==975376==    by 0x4869BC2: ev_invoke_pending (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==975376==    by 0x486DB92: ev_run (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==975376==    by 0x10BFE8: ev_loop (ev.h:842)
==975376==    by 0x10F786: main (main.c:1168)
==975376==  Address 0x8 is not stack'd, malloc'd or (recently) free'd

[SudeepRed]

debugging further but, if you have any clue as to what might be wrong, please let me know!

[SudeepRed]

I have tried to mimic the exact queries that pgbench is using for tests and have done the same through psql and it is working. am not sure what the problem might be ....

[jesperpedersen]

Could it be similar to https://stackoverflow.com/questions/46380140/uthash-delete-and-memory-leaks-valgrind ?

Maybe you can try a LD_PRELOAD based approach... f.ex. https://stackoverflow.com/questions/35976764/overriding-malloc-using-the-ld-preload-and-calls-malloc-in-library-functions and https://github.com/WuBingzheng/libleak

It could be a usage thing, or a bug in uthash itself - if it works without the cache and doesn't with then you know it is in the cache at least

[SudeepRed]

Continuing the discussion from email, to provide better visibility
You have to take a step back and look at it...

You have spent a lot of time on uthash which isn't part of the GSoC
project at all.

Does a single shared memory allocation work ? You need to eliminate
factors that are not part of your project, and then build from there.

Yes it works!

I agree that a week isn't long at this point, but it can be done.

Do a SQL script that does 1 SELECT query, use that for pgbench - and
work from there.

Yes i created a script with a basic query SELECT abalance FROM pgbench_accounts WHERE aid = 1; and it is working as expected. Am able to add, and get the hashentry!
pgbench cmd: pgbench -U postgres -h localhost -p 2345 pgbench_test -f test_script.sql

[SudeepRed]

Tested it with 500 queries and it works too.
Made a pyhton script like so:

import random

# Define the lower and upper bounds for AID values
lower_bound = 1
upper_bound = 100

# Define the number of different queries to generate
query_count = 5000

# Create a set to store unique queries
unique_queries = set()
queries = []

while query_count:
    # Generate a random AID value within the specified range
    random_aid = random.randint(lower_bound, upper_bound)

    # Construct the SQL query
    query = f"SELECT abalance FROM pgbench_accounts WHERE aid = {random_aid};"

    # Add the query to the set
    unique_queries.add(query)
    queries.append(query)
    query_count -=1

# Write the unique queries to a file named test_script.sql
with open("test_script.sql", "w") as file:
    file.write("\n".join(queries))

print("Unique SQL queries have been written to test_script.sql.")
print(f"Number of unique queries generated: {len(unique_queries)}")
print(f"Number of queries generated: {len(queries)}")

[SudeepRed]

Tests and Observations

Test Suit 1

Number of queries: 500
Number of unquie queries: 500
pgbench cmd: pgbench -U postgres -h localhost -p 2345 pgbench_test -f test_script.sql -t 1

Test 1 (Without cache):

pgbench (15.3 (Ubuntu 15.3-1.pgdg20.04+1))
starting vacuum...end.
transaction type: test_script.sql
scaling factor: 1
query mode: simple
number of clients: 1
number of threads: 1
maximum number of tries: 1
number of transactions per client: 1
number of transactions actually processed: 1/1
number of failed transactions: 0 (0.000%)
latency average = 35.089 ms
initial connection time = 13.122 ms
tps = 28.498960 (without initial connection time)

Test 2 (With Cache)

pgbench (15.3 (Ubuntu 15.3-1.pgdg20.04+1))
starting vacuum...end.
transaction type: test_script.sql
scaling factor: 1
query mode: simple
number of clients: 1
number of threads: 1
maximum number of tries: 1
number of transactions per client: 1
number of transactions actually processed: 1/1
number of failed transactions: 0 (0.000%)
latency average = 57.347 ms
initial connection time = 8.343 ms
tps = 17.437704 (without initial connection time)

Test 3 (without pgagroal, using direct postgres)

starting vacuum...end.
transaction type: test_script.sql
scaling factor: 1
query mode: simple
number of clients: 1
number of threads: 1
maximum number of tries: 1
number of transactions per client: 1
number of transactions actually processed: 1/1
number of failed transactions: 0 (0.000%)
latency average = 22.774 ms
initial connection time = 12.031 ms
tps = 43.909722 (without initial connection time)

Test Suit 2

Number of queries: 5000
Number of unquie queries: 100
pgbench cmd: pgbench -U postgres -h localhost -p 2345 pgbench_test -f test_script.sql -t 1

Test 1 (Without cache):

pgbench (15.3 (Ubuntu 15.3-1.pgdg20.04+1))
starting vacuum...end.
transaction type: test_script.sql
scaling factor: 1
query mode: simple
number of clients: 1
number of threads: 1
maximum number of tries: 1
number of transactions per client: 1
number of transactions actually processed: 1/1
number of failed transactions: 0 (0.000%)
latency average = 245.818 ms
initial connection time = 4.500 ms
tps = 4.068050 (without initial connection time)

Test 2 (With Cache):

pgbench (15.3 (Ubuntu 15.3-1.pgdg20.04+1))
starting vacuum...end.
transaction type: test_script.sql
scaling factor: 1
query mode: simple
number of clients: 1
number of threads: 1
maximum number of tries: 1
number of transactions per client: 1
number of transactions actually processed: 1/1
number of failed transactions: 0 (0.000%)
latency average = 98.479 ms
initial connection time = 6.735 ms
tps = 10.154449 (without initial connection time)

Test 3 (without pgagroal, using direct postgres)

pgbench (15.3 (Ubuntu 15.3-1.pgdg20.04+1))
starting vacuum...end.
transaction type: test_script.sql
scaling factor: 1
query mode: simple
number of clients: 1
number of threads: 1
maximum number of tries: 1
number of transactions per client: 1
number of transactions actually processed: 1/1
number of failed transactions: 0 (0.000%)
latency average = 169.529 ms
initial connection time = 10.584 ms
tps = 5.898696 (without initial connection time)

[jesperpedersen]

Good that you have it working now.

We can build from here

[SudeepRed]

Hey Jesper,
I am running into a weird problem.
So running pgbench -S or pgbench -f is working for 1 client. If i do pgbench -S -c 1 or run pgbench -S twice the program just freezes again similar to the problem i faced earlier.
Any idea why it might be happening?
valgrind logs

2023-11-02 01:30:22 DEBUG pool.c:1129 pgagroal_pool_status: 1/100
==24714== Invalid read of size 8
2023-11-02 01:30:22 DEBUG pool.c:1260 pgagroal_pool_status: State: NOTINIT
==24714==    at 0x4C2E4E6: pgagroal_query_cache_get (query_cache.c:106)
==24714==    by 0x4C1E757: session_client (pipeline_session.c:362)
==24714==    by 0x4869BC2: ev_invoke_pending (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==24714==    by 0x486DB92: ev_run (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==24714==    by 0x4C43C71: ev_loop (ev.h:842)
==24714==    by 0x4C44456: pgagroal_worker (worker.c:176)
==24714==    by 0x10FED7: accept_main_cb (main.c:1334)
==24714==    by 0x4869BC2: ev_invoke_pending (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==24714==    by 0x486DB92: ev_run (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==24714==    by 0x10BFE8: ev_loop (ev.h:842)
==24714==    by 0x10F786: main (main.c:1168)
==24714==  Address 0x50d0f48 is 888 bytes inside an unallocated block of size 4,031,504 in arena "client"
==24714== 
2023-11-02 01:30:22 DEBUG pool.c:1261                       Slot: 0
==24714== Invalid read of size 4
==24714==    at 0x4C2E4EA: pgagroal_query_cache_get (query_cache.c:106)
==24714==    by 0x4C1E757: session_client (pipeline_session.c:362)
==24714==    by 0x4869BC2: ev_invoke_pending (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==24714==    by 0x486DB92: ev_run (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==24714==    by 0x4C43C71: ev_loop (ev.h:842)
==24714==    by 0x4C44456: pgagroal_worker (worker.c:176)
==24714==    by 0x10FED7: accept_main_cb (main.c:1334)
==24714==    by 0x4869BC2: ev_invoke_pending (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==24714==    by 0x486DB92: ev_run (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==24714==    by 0x10BFE8: ev_loop (ev.h:842)
==24714==    by 0x10F786: main (main.c:1168)
==24714==  Address 0x8 is not stack'd, malloc'd or (recently) free'd
==24714== 
==24714== 
==24714== Process terminating with default action of signal 11 (SIGSEGV)
==24714==  Access not within mapped region at address 0x8
==24714==    at 0x4C2E4EA: pgagroal_query_cache_get (query_cache.c:106)
==24714==    by 0x4C1E757: session_client (pipeline_session.c:362)
==24714==    by 0x4869BC2: ev_invoke_pending (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==24714==    by 0x486DB92: ev_run (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==24714==    by 0x4C43C71: ev_loop (ev.h:842)
==24714==    by 0x4C44456: pgagroal_worker (worker.c:176)
==24714==    by 0x10FED7: accept_main_cb (main.c:1334)
==24714==    by 0x4869BC2: ev_invoke_pending (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==24714==    by 0x486DB92: ev_run (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==24714==    by 0x10BFE8: ev_loop (ev.h:842)
==24714==    by 0x10F786: main (main.c:1168)
==24714==  If you believe this happened as a result of a stack
==24714==  overflow in your program's main thread (unlikely but
==24714==  possible), you can try to increase the size of the
==24714==  main thread stack using the --main-stacksize= flag.
2023-11-02 01:30:22 DEBUG pool.c:1262                       FD: -1
==24714==  The main thread stack size used in this run was 8388608.

pgbench output

pgbench (15.3 (Ubuntu 15.3-1.pgdg20.04+1))
starting vacuum...end.
pgbench: error: client 1 aborted in command 1 (SQL) of script 0; perhaps the backend died while processing
transaction type: <builtin: select only>
scaling factor: 1
query mode: simple
number of clients: 2
number of threads: 1
maximum number of tries: 1
number of transactions per client: 1
number of transactions actually processed: 1/2
number of failed transactions: 0 (0.000%)
latency average = 833.698 ms
initial connection time = 75.465 ms
tps = 2.398950 (without initial connection time)
pgbench: error: Run was aborted; the above results are incomplete.

[jesperpedersen]

It sounds like you are reading passed the end of the key - make sure that the key is the query plus a \0 at the end

[SudeepRed]

I solved this problem. I wasn't freeing the shared memory between client/server in session pipeline which was used to pass the client msg to server. Now i have another problem, so when cache is enabled am able to only connect 22 clients. i.e `pgbench -S -c 22 `works but `pgbench -S -c 23 and above` fails with the following error pgbench (15.3 (Ubuntu 15.3-1.pgdg20.04+1)) starting vacuum...end. pgbench: error: connection to server at "localhost" (127.0.0.1), port 2345 failed: FATAL: sorry, too many clients already pgbench: error: could not create connection for client 23 Edit: there was some problem with my postgres, after restarting the service it worked :)

[jesperpedersen]

In pipeline_session.c the cache should work between requests - that is precisely the point of the feature.

But if it is connection level then it is local to the connection and you should only clear it upon client disconnect. The harder one is the global cache, where you have to use a lock...

[SudeepRed]

I have implemented locking here: 6fe7545
but im having a race condition when a client fetches from the cache (cache_get). Im not sure where i am missing a lock, could you please have a look at it once/test it out on you machine?

[SudeepRed]

Hi @jesperpedersen
I found the cause of the race condition, that is im unable to do any hash operation after a client is done with its queries, thus the lock is never released.
I think it has something to do with uthash itself.
So to prove my point, i ran a custom sql query script with pgbench which has exactly two queries:

SELECT abalance FROM pgbench_accounts WHERE aid = 1;
SELECT abalance FROM pgbench_accounts WHERE aid = 1;

The aim with this script is to add the query result to hash and then for the second query get the hashed result.
Now this is working like a charm for 1 client, it doesn't matter if i have 50k queries, it works.
But as soon as i have a second client trying to do any operation, the program just freezes, when the second client tries to do a HASH_FIND, even though the first client was able to get the hashed result using HASH_FIND.
there are no memory leaks (used valgrind to check)
Valgrind logs at

==82495== Invalid read of size 8
==82495==    at 0x4C2F242: pgagroal_query_cache_get (query_cache.c:121)
==82495==    by 0x4C1EA2B: session_client (pipeline_session.c:410)
==82495==    by 0x4869BC2: ev_invoke_pending (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==82495==    by 0x486DB92: ev_run (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==82495==    by 0x4C44AFD: ev_loop (ev.h:842)
==82495==    by 0x4C452E2: pgagroal_worker (worker.c:176)
==82495==    by 0x10FED7: accept_main_cb (main.c:1334)
==82495==    by 0x4869BC2: ev_invoke_pending (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==82495==    by 0x486DB92: ev_run (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==82495==    by 0x10BFE8: ev_loop (ev.h:842)
==82495==    by 0x10F786: main (main.c:1168)
==82495==  Address 0x50c19e8 is 2,040 bytes inside an unallocated block of size 4,058,608 in arena "client"
==82495== 
==82495== Invalid read of size 4
==82495==    at 0x4C2F246: pgagroal_query_cache_get (query_cache.c:121)
==82495==    by 0x4C1EA2B: session_client (pipeline_session.c:410)
==82495==    by 0x4869BC2: ev_invoke_pending (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==82495==    by 0x486DB92: ev_run (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==82495==    by 0x4C44AFD: ev_loop (ev.h:842)
==82495==    by 0x4C452E2: pgagroal_worker (worker.c:176)
==82495==    by 0x10FED7: accept_main_cb (main.c:1334)
==82495==    by 0x4869BC2: ev_invoke_pending (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==82495==    by 0x486DB92: ev_run (in /usr/lib/x86_64-linux-gnu/libev.so.4.0.0)
==82495==    by 0x10BFE8: ev_loop (ev.h:842)
==82495==    by 0x10F786: main (main.c:1168)
==82495==  Address 0x8 is not stack'd, malloc'd or (recently) free'd

[jesperpedersen]

Can you do a heavy (that takes a long time) query where the result cache could be of benefit ?

[SudeepRed]

I tested it with 20k queries, out of which 100 were unique.
Example query: SELECT abalance FROM pgbench_accounts WHERE aid = XX;

Without Cache:

pgbench (15.3 (Ubuntu 15.3-1.pgdg20.04+1))
starting vacuum...end.
transaction type: test_script.sql
scaling factor: 1
query mode: simple
number of clients: 1
number of threads: 1
maximum number of tries: 1
number of transactions per client: 1
number of transactions actually processed: 1/1
number of failed transactions: 0 (0.000%)
latency average = 2410.885 ms
initial connection time = 8.827 ms
tps = 0.414785 (without initial connection time)

With Cache:

pgbench (15.3 (Ubuntu 15.3-1.pgdg20.04+1))
starting vacuum...end.
transaction type: test_script.sql
scaling factor: 1
query mode: simple
number of clients: 1
number of threads: 1
maximum number of tries: 1
number of transactions per client: 1
number of transactions actually processed: 1/1
number of failed transactions: 0 (0.000%)
latency average = 1473.437 ms
initial connection time = 7.573 ms
tps = 0.678685 (without initial connection time)

[SudeepRed]

I dont think O(n) linear search is the right approach for this. The TPS difference is also not that significant.

[jesperpedersen]

No, O(n) isn't ideal - but the list is so small atm that going to O(1) - e.g. a hash - won't make a big difference. Right now, we need to figure where the time is spent by having the timestamp and potential locking overhead.

Having graphs of TPS and latency will help us - but at the moment it doesn't seem to be of benefit to have the extra complexity in the code - and that is ok too.

[SudeepRed]

I tried running pgbench -U postgres -h localhost -p 2345 pgbench_test -S -M simple -c 100
and there is no significant difference having cache enabled (maybe i have high hopes 😮‍💨 )

Without cache:

pgbench (15.3 (Ubuntu 15.3-1.pgdg20.04+1))
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 1
query mode: simple
number of clients: 100
number of threads: 100
maximum number of tries: 1
number of transactions per client: 100
number of transactions actually processed: 10000/10000
number of failed transactions: 0 (0.000%)
latency average = 69.186 ms
initial connection time = 1074.617 ms
tps = 1445.370349 (without initial connection time)

With cache:

pgbench (15.3 (Ubuntu 15.3-1.pgdg20.04+1))
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 1
query mode: simple
number of clients: 100
number of threads: 1
maximum number of tries: 1
number of transactions per client: 10
number of transactions actually processed: 1000/1000
number of failed transactions: 0 (0.000%)
latency average = 81.573 ms
initial connection time = 384.847 ms
tps = 1225.903338 (without initial connection time)

[SudeepRed]

Hi @jesperpedersen
So i was trying to figure out why exactly is the O(n) approach is doing so bad(ik its not ideal but still), here what i found out:
Meaning of the logs -> (strncmp result, the key to be searched, the key in cache, cache id (array index))

2023-11-05 21:39:43 WARN  query_cache.c:115 from cache GET to comapre -2, SELECT abalance FROM pgbench_accounts WHERE aid = 66328;, SELECT abalance FROM pgbench_accounts WHERE aid = 48337;, 0
2023-11-05 21:39:43 WARN  query_cache.c:115 from cache GET to comapre -5, SELECT abalance FROM pgbench_accounts WHERE aid = 66328;, SELECT abalance FROM pgbench_accounts WHERE aid = 14561;, 1
2023-11-05 21:39:43 WARN  query_cache.c:115 from cache GET to comapre 1, SELECT abalance FROM pgbench_accounts WHERE aid = 66328;, SELECT abalance FROM pgbench_accounts WHERE aid = 74474;, 2
2023-11-05 21:39:43 WARN  query_cache.c:115 from cache GET to comapre -83, SELECT abalance FROM pgbench_accounts WHERE aid = 66328;, , 3
2023-11-05 21:39:43 WARN  query_cache.c:115 from cache GET to comapre -83, SELECT abalance FROM pgbench_accounts WHERE aid = 66328;, , 4
2023-11-05 21:39:43 WARN  query_cache.c:115 from cache GET to comapre -83, SELECT abalance FROM pgbench_accounts WHERE aid = 66328;, , 5
2023-11-05 21:39:43 WARN  query_cache.c:115 from cache GET to comapre -83, SELECT abalance FROM pgbench_accounts WHERE aid = 66328;, , 6
2023-11-05 21:39:43 WARN  query_cache.c:115 from cache GET to comapre -1, SELECT abalance FROM pgbench_accounts WHERE aid = 66328;, SELECT abalance FROM pgbench_accounts WHERE aid = 65084;, 7
2023-11-05 21:39:43 WARN  query_cache.c:115 from cache GET to comapre -2, SELECT abalance FROM pgbench_accounts WHERE aid = 66328;, SELECT abalance FROM pgbench_accounts WHERE aid = 44793;, 8
2023-11-05 21:39:43 WARN  query_cache.c:115 from cache GET to comapre 3, SELECT abalance FROM pgbench_accounts WHERE aid = 66328;, SELECT abalance FROM pgbench_accounts WHERE aid = 93262;, 9
2023-11-05 21:39:43 WARN  query_cache.c:115 from cache GET to comapre 1, SELECT abalance FROM pgbench_accounts WHERE aid = 66328;, SELECT abalance FROM pgbench_accounts WHERE aid = 73234;, 10
2023-11-05 21:39:43 WARN  query_cache.c:115 from cache GET to comapre -83, SELECT abalance FROM pgbench_accounts WHERE aid = 66328;, , 11
2023-11-05 21:39:43 WARN  query_cache.c:115 from cache GET to comapre -83, SELECT abalance FROM pgbench_accounts WHERE aid = 66328;, , 12
2023-11-05 21:39:43 WARN  query_cache.c:115 from cache GET to comapre -83, SELECT abalance FROM pgbench_accounts WHERE aid = 66328;, , 13
2023-11-05 21:39:43 WARN  query_cache.c:115 from cache GET to comapre -83, SELECT abalance FROM pgbench_accounts WHERE aid = 66328;, , 14
2023-11-05 21:39:43 WARN  query_cache.c:115 from cache GET to comapre -83, SELECT abalance FROM pgbench_accounts WHERE aid = 66328;, , 15

So as you can see some entries from the cache are just malformed. idk why this is happening tho.
one thing to note is that this behaviour is only happening when we have more than 1 client.
Any ideas as to what might be causing this?

[jesperpedersen]

connection_details shouldn't be in this output at all - use pgagroal_backtrace() to figure out why

[SudeepRed]

So i just removed all the locks and there seems to be a slight improvement!

With cache:

pgbench (15.3 (Ubuntu 15.3-1.pgdg20.04+1))
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 1
query mode: simple
number of clients: 100
number of threads: 1
maximum number of tries: 1
number of transactions per client: 10
number of transactions actually processed: 1000/1000
number of failed transactions: 0 (0.000%)
latency average = 7.630 ms
initial connection time = 1067.837 ms
tps = 13106.847017 (without initial connection time)

Without cache:

pgbench (15.3 (Ubuntu 15.3-1.pgdg20.04+1))
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 1
query mode: simple
number of clients: 100
number of threads: 1
maximum number of tries: 1
number of transactions per client: 10
number of transactions actually processed: 1000/1000
number of failed transactions: 0 (0.000%)
latency average = 6.448 ms
initial connection time = 907.445 ms
tps = 15508.444348 (without initial connection time)

for pgbench -U postgres -h localhost -p 2345 pgbench_test -S -M simple -c 100
Im having just 15 cache hits, and thats the reason i think cache is falling behind.

[SudeepRed]

connection_details shouldn't be in this output at all

Why shouldn't it be there?
Im using debug mode to test all of this out maybe thats why
But the impact it has is negligible isn't it?

[jesperpedersen]

Well, clearly not if it is showing up in the perf output...

[SudeepRed]

It happens in master branch too, so its not really specific to my change.
I will have a look at this tommorow.
Here are the results with release build:

Without cache

pgbench (15.3 (Ubuntu 15.3-1.pgdg20.04+1))
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 1
query mode: simple
number of clients: 100
number of threads: 100
maximum number of tries: 1
number of transactions per client: 10
number of transactions actually processed: 1000/1000
number of failed transactions: 0 (0.000%)
latency average = 5.080 ms
initial connection time = 1089.692 ms
tps = 19684.264399 (without initial connection time)

With Cache:

pgbench (15.3 (Ubuntu 15.3-1.pgdg20.04+1))
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 1
query mode: simple
number of clients: 100
number of threads: 100
maximum number of tries: 1
number of transactions per client: 10
number of transactions actually processed: 1000/1000
number of failed transactions: 0 (0.000%)
latency average = 5.309 ms
initial connection time = 1081.112 ms
tps = 18835.584186 (without initial connection time)

its better without cache tbh. 😞

[SudeepRed]

Hi @jesperpedersen
Since O(n) implmentation worked, i thought of re-implmenting uthash once again and seeing if it would work, and it did! 🥳
This is the hash structure:

struct hashTable
{
   char key[1024];
   struct hashEntry* data;
   UT_hash_handle hh;
} __attribute__ ((aligned (64)));

And i switched to HASH_ADD_STR and HASH_FIND_STR instead of HASH_ADD_KEYPTR and HASH_FIND
But the results remain the same.

All tests were done in release build, session pipeline
pgbench -U postgres -h localhost -p 2345 pgbench_test -S -M simple -c 100 -j 100

Without cache:

pgbench (15.3 (Ubuntu 15.3-1.pgdg20.04+1))
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 1
query mode: simple
number of clients: 100
number of threads: 100
maximum number of tries: 1
number of transactions per client: 10
number of transactions actually processed: 1000/1000
number of failed transactions: 0 (0.000%)
latency average = 4.155 ms
initial connection time = 1070.791 ms
tps = 24067.388688 (without initial connection time)

With cache(uthash):

pgbench (15.3 (Ubuntu 15.3-1.pgdg20.04+1))
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 1
query mode: simple
number of clients: 100
number of threads: 100
maximum number of tries: 1
number of transactions per client: 10
number of transactions actually processed: 1000/1000
number of failed transactions: 0 (0.000%)
latency average = 5.506 ms
initial connection time = 1056.126 ms
tps = 18162.334950 (without initial connection time)

here is the perf report:

[SudeepRed]

We can now conclude that having a cache will not boost performance.

[SudeepRed]

Here are the graphs:

[jesperpedersen]

Thank you for the data !

I think it is clear from this that we are not going forward with a cache.

Thanks for your work on this !