Cached query returns null for newly inserted data

[aarjan]

I connected my node api to the readyset docker service.
A user fetching query was cached in readyset.
But on creating new user, i do not get the new user data from the api.
I could see the new inserted row in both mysql db and in the readyset service through mysql shell.

This is the config for readyset in the docker-compose file which is working in swarm mode:

  readyset:
    image: public.ecr.aws/readyset/readyset:latest
    ports:
      - 5433:5433
      - 3307:3307
    depends_on:
      - mysql
    env_file: .env
    networks:
      - backend
    volumes:
      - ./readyset:/state
    environment:
      STANDALONE: "1"
      DB_DIR: "/state"
      DATABASE_TYPE: mysql
      QUERY_CACHING: explicit
      DEPLOYMENT: "quickstart_docker"
      UPSTREAM_DB_URL: mysql://root:root@mysql:3306/testdb
      LISTEN_ADDRESS: "0.0.0.0:5433"
    logging:
      <<: *logging

This is the readyset_docker logs when i fire the api request

nf_readyset.1.msuofpokgq43@ip-172-31-27-196    | 2023-02-15T15:36:14.933119Z  INFO readyset: Accepted new connection context=LogContext({"deployment": "quickstart_docker"})
nf_readyset.1.msuofpokgq43@ip-172-31-27-196    | 2023-02-15T15:36:14.933265Z  INFO Connecting to MySQL upstream{host=mysql port=3306 user=root}: readyset_mysql::upstream: Establishing connection context=LogContext({"deployment": "quickstart_docker"})
nf_readyset.1.msuofpokgq43@ip-172-31-27-196    | 2023-02-15T15:36:14.939268Z  INFO Connecting to MySQL upstream{host=mysql port=3306 user=root}: readyset_mysql::upstream: Established connection to upstream context=LogContext({"deployment": "quickstart_docker"})

[alanamarzoev]

Hey @aarjan!

Just to confirm, when you're running the cached query in ReadySet (using the MySQL shell), you're seeing the correct cached query result that reflects the latest write? The issue is just that when the API calls ReadySet, a stale value is returned?

[aarjan]

@alanamarzoev yes, if i use the mysql shell to connect with readyset in the readyset docker container, i can see the newly inserted data returned from that query.
But the API calls returns an empty response.

[alanamarzoev]

How are you accessing ReadySet from the API? Are you using a specific ORM/DB client?

[aarjan]

@alanamarzoev I am using Prisma where the host=readyset & port=5433

[dfwilbanks395]

Did you provide mysql://root:root@mysql:5433/testdb as the connection string to prisma? Also are you able to get any results from your API calls while connected to ReadySet, but before caching any queries?

[aarjan]

This is the dsn, mysql://root:root@readyset:5433/testdb?charset=utf8mb4&pool_timeout=50
All other uncached queries are running fine.

[dfwilbanks395]

Would you be able to share the query you're caching? Either here or via email with dan@readyset.io.

We could have a bug with executing this particular query. Running the query over the mysql shell could hit a different path in our code, since those queries are run with the query protocol, whereas prisma is likely sending queries using the extended query (prepare/execute) protocol.

[aarjan]

I tried both of these queries in mysql shell from readyset.
If i remove the testdb.student in the where query it works and returns the data.
In the main db shell, both the query works as usual.

MySQL [testdb]> SELECT `testdb`.`student`.`id`, `testdb`.`student`.`avatar`, `testdb`.`student`.`profile_pic`, `testdb`.`student`.`country`, `testdb`.`student`.`state`, `testdb`.`student`.`college`, `testdb`.`student`.`year`, `testdb`.`student`.`uuid`, `testdb`.`student`.`bio`, `testdb`.`student`.`email`, `testdb`.`student`.`phone`, `testdb`.`student`.`gender`, `testdb`.`student`.`address`, `testdb`.`student`.`fullname`, `testdb`.`student`.`status`, `testdb`.`student`.`password`, `testdb`.`student`.`exams` FROM `testdb`.`student` WHERE `testdb`.`student`.`uuid` = '7d59d23a-781d-4102-bed5-3489c62a3373';
Empty set (0.000 sec)

MySQL [testdb]> SELECT `testdb`.`student`.`id`, `testdb`.`student`.`avatar`, `testdb`.`student`.`profile_pic`, `testdb`.`student`.`country`, `testdb`.`student`.`state`, `testdb`.`student`.`college`, `testdb`.`student`.`year`, `testdb`.`student`.`uuid`, `testdb`.`student`.`bio`, `testdb`.`student`.`email`, `testdb`.`student`.`phone`, `testdb`.`student`.`gender`, `testdb`.`student`.`address`, `testdb`.`student`.`fullname`, `testdb`.`student`.`status`, `testdb`.`student`.`password`, `testdb`.`student`.`exams` FROM `testdb`.`student` WHERE `uuid` = '7d59d23a-781d-4102-bed5-3489c62a3373';
+-----+----------------------------------------------------------------------------------------+-------------+---------+-------+---------+------+--------------------------------------+------+-------------------+-------+--------+---------+------------------+--------+----------+-------+
| id  | avatar                                                                                 | profile_pic | country | state | college | year | uuid                                 | bio  | email             | phone | gender | address | fullname         | status | password | exams |
+-----+----------------------------------------------------------------------------------------+-------------+---------+-------+---------+------+--------------------------------------+------+-------------------+-------+--------+---------+------------------+--------+----------+-------+
| 172 | https://lh3.googleusercontent.com/a/AEdFTp5R0JLEWccUm117u6IDlu-iJkL0_2iG8sVaiuq1=s96-c | NULL        | NULL    | NULL  | NULL    | NULL | 7d59d23a-781d-4102-bed5-3489c62a3373 | NULL | test@gmail.com | NULL  | NULL   | NULL    | Test user |      1 | NULL     | NULL  |
+-----+----------------------------------------------------------------------------------------+-------------+---------+-------+---------+------+--------------------------------------+------+-------------------+-------+--------+---------+------------------+--------+----------+-------+
1 row in set (0.008 sec)

[dfwilbanks395]

This query is simple enough that we're probably dealing with an issue of replicating the testdb.student table instead.

One way we could end up with a bug like this is if we fail to correctly process a prisma migration. You could try restarting your app against the backing DB, running your migrations, and then adding ReadySet to your application, if possible, without re-running any migrations. If the query works after caching against ReadySet, then we know the bug comes from handling a migration.

Also, one way we could verify that we've failed to replicate data is by looking at the graphviz of all cached queries. You can get the graphviz of all queries by running explain graphviz against ReadySet via the mysql shell. At the top of the graph, we should see the base tables, and in the upper right hand corner of each base table we should see the approximate number of rows replicated for each base table. I'd be happy to check this if you post the output of explain graphviz.

Incidentally, the reason the query works after removing testdb.student is likely that we don't consider that to be the same query, and proxy it to mysql instead. You can check whether a query is executed on readyset or proxied via mysql by running explain last statement after running the query against the mysql shell.

[aarjan]

Hi @dfwilbanks395,

One way we could end up with a bug like this is if we fail to correctly process a prisma migration

I tried this but didn't work.

Yes, the query works after removing testdb.student because it was fetching from upstream.

I have emailed you the graphviz output, hope that helps.