hasura / hasura/graphql-engine
[Bug] Metadata resource_version is incremented on changes that don't actually affect metadata
- Dominant language
- TypeScript
- Stars
- 32.1k
- Forks
- 3k
- PR merge metrics
- PR metrics pending
Description
### Issue Description
~~Hasura queries of type `run_sql` that specify more than one SQL statement lead to each _additional_ statement individually triggering the server metadata catalog function `setMetadataInCatalog`.~~
~~Consider the following query generated by the console when creating a table with a comment set:~~
```
"query": {
"resource_version": 2,
"args": [
{
"args": {
"cascade": false,
"source": "default",
"sql": "CREATE TABLE \"public\".\"test_table_nok\" (\"id\" serial NOT NULL, PRIMARY KEY (\"id\") );COMMENT ON TABLE \"public\".\"test_table_nok\" IS E'COMMENTTEST';",
"read_only": false
},
"type": "run_sql"
}
],
"source": "default",
"type": "bulk"
}
```
~~As this single operation contains two SQL statements, `setMetadataInCatalog` is called twice and fails on the second call as it's still referencing the out-of-date `resource_version` value of `2`, due to the first call having already incremented it to `3` in the ongoing transaction.~~
~~This increments the metadata `resource_version` more than once per operation, causing the second execution of the `setMetadataInCatalog` function to throw a 409 error and the whole metadata transaction being cancelled and rolled back. (while the initial CREATE TABLE query is committed).~~
~~See **additional info** below for verbose logs of this occuring.~~
___
#### UPDATE
Running an identical operation through the Raw SQL console page succeeds in creating the table with consistent metadata. The only difference here is that the Raw SQL action refetches the metadata after running the query and before tracking any new items, so I've replicated this behaviour for table creation which seems to work well. See PR #7330.
This still leaves some inconsistent behavior open in the server API:
1. Creating a table no other modifying statements will not cause the server to trigger a `hdb_metadata` update. See for example the following query:
```CREATE TABLE \"public\".\"test_table_ok\" (\"id\" serial NOT NULL, PRIMARY KEY (\"id\") );```
2. Creating a table with any additional modifying statements will cause the server to trigger a `hdb_metadata` update, even if the metadata is actually unchanged; all that happens is we see `resource_version` getting incremented. See for example the following query:
```CREATE TABLE \"public\".\"test_table_nok\" (\"id\" serial NOT NULL, PRIMARY KEY (\"id\") );COMMENT ON TABLE \"public\".\"test_table_nok\" IS E'COMMENTTEST';",```
The metadata state of both API queries should be the same: no changes affecting metadata have been undertaken, thus metadata should not be updated.
After some browsing of the API Query logic and with a now slightly less shallow understanding of it I have two possible suggestions:
- **The hasura server should only increment the metadata `resource_version` if the metadata has actually changed**
_An additional check in the server's `Query.hs:runQuery` could be added to consider whether the metadata has actually changed before running `setMetadata`. This is a quick and dirty fix._
- **RQLQuerys affecting only untracked item(s) should evaluate as `queryModifiesSchema == false` where they currently evaluate with `queryModifiesSchema == true`**
The table creation example with a comment is a perfect storm example of this: The `CREATE TABLE` statement itself is evaluated in the server's Query.hs to not modify schema, so no metadata update is triggered, but the `COMMENT ON TABLE` statement directly following it however is evaluated to modify schema and triggers `setMetadata`.
_A solution here could be to extend certain `queryModifiesSchema` types to also check if the query actually affects any resources that are tracked in metadata, as in the case of adding a comment to a yet to be tracked table will result in no actual metadata change. I also think that this is a more elegant fix as it prevents code unnecessary code paths being taken vs. a brute force check of newMetadata == oldMetadata suggested in the previous bullet point._
___
### Issue Type
bug
### Version
starting with Hasura 2.x in combination with PostgreSQL 12 or 13
_(other database backends are possibly also affected, but were not tested)_
### How to Reproduce
1. Create a fresh Hasura 2.0.4 instance and link it with an empty PostgreSQL database.
2. Open the web console and enact a change which executes a single query with two or more statements
(e.g. creating a table in the console with an updated_at field trigger, or a table comment set)
3. Observe the console throwing the `Metadata is Out-of-Date` error and the SQL query log indicating metadate has been updated server-side
### Additional Info
Hasura + Postgres logs from a Docker environment (JSON has been formatted for readability)
```
hasura-db | 2021-07-30 17:55:55.453 UTC [80] LOG: statement: CREATE TABLE "public"."test_table_nok" ("id" serial NOT NULL, PRIMARY KEY ("id") );COMMENT ON TABLE "public"."test_table_nok" IS E'COMMENTTEST';
hasura-db | 2021-07-30 17:55:55.516 UTC [79] LOG: execute 9:
hasura-db | INSERT INTO hdb_catalog.hdb_metadata(id, metadata)
hasura-db | VALUES (1, $1::json)
hasura-db | ON CONFLICT (id) DO UPDATE SET
hasura-db | metadata = $1::json,
hasura-db | resource_version = hdb_catalog.hdb_metadata.resource_version + 1
hasura-db | WHERE hdb_catalog.hdb_metadata.resource_version = $2
hasura-db | RETURNING resource_version
hasura-db |
hasura-db | 2021-07-30 17:55:55.516 UTC [79] DETAIL: parameters: $1 = '
{
"sources": [
{
"kind": "postgres",
"name": "default",
"tables": [
{
"table": {
"schema": "public",
"name": "test_table_ok"
}
}
],
"configuration": {
"connection_info": {
"use_prepared_statements": true,
"database_url": {
"from_env": "HASURA_GRAPHQL_DATABASE_URL"
},
"isolation_level": "read-committed",
"pool_settings": {
"connection_lifetime": 600,
"retries": 1,
"idle_timeout": 180,
"max_connections": 50
}
}
}
}
],
"version": 3
}
', $2 = '2'
hasura-db | 2021-07-30 17:55:55.527 UTC [79] LOG: execute 10:
hasura-db | INSERT INTO hdb_catalog.hdb_schema_notifications(id, notification, resource_version, instance_id)
hasura-db | VALUES (1, $1::json, $2, $3::uuid)
hasura-db | ON CONFLICT (id) DO UPDATE SET
hasura-db | notification = $1::json,
hasura-db | resource_version = $2,
hasura-db | instance_id = $3::uuid
hasura-db |
hasura-db | 2021-07-30 17:55:55.527 UTC [79] DETAIL: parameters: $1 = '{"metadata":false,"remote_schemas":[],"sources":["default"]}', $2 = '3', $3 = 'd34094f5-af4d-43c6-8b4b-c63a6eb3106e'
hasura-app |
{
"type": "http-log",
"timestamp": "2021-07-30T17:55:55.538+0000",
"level": "info",
"detail": {
"operation": {
"query_execution_time": 9.658332e-2,
"user_vars": {
"x-hasura-role": "admin"
},
"request_id": "b0994433-5510-46e7-9806-c5afb7287ad1",
"response_size": 58,
"query": {
"resource_version": 2,
"args": [
{
"args": {
"cascade": false,
"source": "default",
"sql": "CREATE TABLE \"public\".\"test_table_nok\" (\"id\" serial NOT NULL, PRIMARY KEY (\"id\") );COMMENT ON TABLE \"public\".\"test_table_nok\" IS E'COMMENTTEST';",
"read_only": false
},
"type": "run_sql"
}
],
"source": "default",
"type": "bulk"
},
"request_read_time": 7.09e-6
},
"request_id": "b0994433-5510-46e7-9806-c5afb7287ad1",
"http_info": {
"status": 200,
"http_version": "HTTP/1.1",
"url": "/v2/query",
"ip": "79.248.33.201",
"method": "POST",
"content_encoding": "gzip"
}
}
}
hasura-db | 2021-07-30 17:55:55.742 UTC [79] LOG: execute 9:
hasura-db | INSERT INTO hdb_catalog.hdb_metadata(id, metadata)
hasura-db | VALUES (1, $1::json)
hasura-db | ON CONFLICT (id) DO UPDATE SET
hasura-db | metadata = $1::json,
hasura-db | resource_version = hdb_catalog.hdb_metadata.resource_version + 1
hasura-db | WHERE hdb_catalog.hdb_metadata.resource_version = $2
hasura-db | RETURNING resource_version
hasura-db |
hasura-db | 2021-07-30 17:55:55.742 UTC [79] DETAIL: parameters: $1 = '
{
"sources": [
{
"kind": "postgres",
"name": "default",
"tables": [
{
"table": {
"schema": "public",
"name": "test_table_nok"
}
},
{
"table": {
"schema": "public",
"name": "test_table_ok"
}
}
],
"configuration": {
"connection_info": {
"use_prepared_statements": true,
"database_url": {
"from_env": "HASURA_GRAPHQL_DATABASE_URL"
},
"isolation_level": "read-committed",
"pool_settings": {
"connection_lifetime": 600,
"retries": 1,
"idle_timeout": 180,
"max_connections": 50
}
}
}
}
],
"version": 3
}
', $2 = '2'
hasura-app |
{
"type": "schema-sync-thread",
"timestamp": "2021-07-30T17:55:55.538+0000",
"level": "debug",
"detail": {
"thread_type": "processor",
"info": {
"message": "DEBUG: refreshSchemaCache Called: engineResourceVersion: MetadataResourceVersion {getMetadataResourceVersion = 2}, fresh resource version: MetadataResourceVersion {getMetadataResourceVersion = 3}"
}
}
}
hasura-app |
{
"type": "schema-sync-thread",
"timestamp": "2021-07-30T17:55:55.538+0000",
"level": "info",
"detail": {
"thread_type": "processor",
"info": {
"message": "Schema Version changed with no notifications"
}
}
}
hasura-app |
{
"type": "http-log",
"timestamp": "2021-07-30T17:55:55.538+0000",
"level": "error",
"detail": {
"operation": {
"user_vars": {
"x-hasura-role": "admin"
},
"error": {
"path": "$",
"error": "metadata resource version referenced (2) did not match current version",
"code": "conflict"
},
"request_id": "bccd1476-17b9-451a-a64c-67d9d5ec4b30",
"response_size": 111,
"query": {
"resource_version": 2,
"args": [
{
"args": {
"source": "default",
"table": {
"schema": "public",
"name": "test_table_nok"
}
},
"type": "pg_track_table"
}
],
"source": "default",
"type": "bulk"
}
},
"request_id": "bccd1476-17b9-451a-a64c-67d9d5ec4b30",
"http_info": {
"status": 409,
"http_version": "HTTP/1.1",
"url": "/v1/metadata",
"ip": "79.248.33.201",
"method": "POST",
"content_encoding": null
}
}
}
### Manually refreshed metadata ###
hasura-app |
{
"type": "http-log",
"timestamp": "2021-07-30T17:56:08.381+0000",
"level": "info",
"detail": {
"operation": {
"query_execution_time": 1.064492e-3,
"user_vars": {
"x-hasura-role": "admin"
},
"request_id": "4f0945e7-2f34-493a-af40-a517582c10b1",
"response_size": 293,
"query": {
"args": {
},
"version": 2,
"type": "export_metadata"
},
"request_read_time": 8.379e-6
},
"request_id": "4f0945e7-2f34-493a-af40-a517582c10b1",
"http_info": {
"status": 200,
"http_version": "HTTP/1.1",
"url": "/v1/metadata",
"ip": "79.248.33.201",
"method": "POST",
"content_encoding": "gzip"
}
}
}
```
Contributor guide
Research direction
Start with Query.hs:runQuery and the setMetadataInCatalog path; reproduce the /v2/query bulk request using the multi-statement PostgreSQL example. Compare it with the single-statement case and verify that operations affecting only untracked items leave resource_version unchanged without the metadata conflict.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- graphql, haskell, postgresql
- Domain
- api, backend, databases
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 40/100