Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Data Connect @check in query doesn't work - should it? #8133

Open
zmullett opened this issue Jan 23, 2025 · 4 comments
Open

Data Connect @check in query doesn't work - should it? #8133

zmullett opened this issue Jan 23, 2025 · 4 comments
Assignees
Labels
emulator: dataconnect Issues related to the dataconnect emulator type: bug

Comments

@zmullett
Copy link

zmullett commented Jan 23, 2025

[REQUIRED] Environment info

firebase-tools: 13.29.1

Platform: macOS

[REQUIRED] Test case

Attempting to check for membership by row presence in OrganizationMembership when querying for an Organization row by ID.

schema.gql:

type Organization @table {
  id: UUID! @default(expr: "uuidV4()")
  title: String!
}

type OrganizationMembership @table(key: ["organization", "uid"]) {
  organization: Organization!
  uid: String!
}

queries.gql:

query GetOrganizationById($organizationId: UUID!) @auth(level: USER) {
  organization(id: $organizationId) {
    organizationMemberships_on_organization(
      where: { uid: { eq_expr: "auth.uid" } }
    ) @check {
      uid  # dummy field
    }
    title
  }
}

[REQUIRED] Steps to reproduce

  1. Add test Organization and OrganizationMembership rows. The following mutations could be used:
mutation CreateOrganization($title: String!) @auth(level: NO_ACCESS) {
  organization_insert(data: { title: $title })
}

mutation UpsertOrganizationMembership($organizationId: UUID!, $uid: String!)
@auth(level: NO_ACCESS) {
  organizationMembership_upsert(
    data: { organizationId: $organizationId, uid: $uid }
  )
}

[REQUIRED] Expected behavior

Inclusion of the @check directive has the effect of returning an error if the expression evaluates to false, otherwise is a no-op.

[REQUIRED] Actual behavior

W0123 17:08:33.851394   32250 engine.go:152] [engine.Service /emulator/my-project ebb4] ExecuteQuery GetOrganizationById: failed. Connector: default
Auth: user of {...some-firebase-auth-details...}
Variables:
{
   "organizationId": "9ffb14d5-fbd9-4ee9-8cb8-10a37ba153ab"
 }
Errors: input: cannot commit transaction: pq: unexpected transaction status idle

Data:
[...see below...]
sources: connector/mutations.gql [483B] connector/queries.gql [673B] 

The Data array, decoded:

{
   "organization": {
     "organizationMemberships_on_organization": [
       {
         "uid": "some-firebase-auth-uid"
       }
     ],
     "title": "Test Organization"
   }
 }

The emulator is then left in a broken state and needs restarting. Prior to restarting, any schema modifications and subsequent queries result in a such an error: SQL Error: pq: prepared statement "1" already exists

@aalej aalej added the emulator: dataconnect Issues related to the dataconnect emulator label Jan 23, 2025
@joehan
Copy link
Contributor

joehan commented Jan 23, 2025

Thanks for reporting this! @\check should work in queries, so this definitely seems like a bug - looking into it now

@joehan
Copy link
Contributor

joehan commented Jan 24, 2025

I was able to repro the issue on the emulator, and also verified that this is working in production. This seems to be an issue with how PGLite is handling transactions/multiple connections.

Debug logs from repro:

[debug] [2025-01-24T00:22:50.776Z] I0123 16:22:50.776150   24430 executor.go:96] [operation "UpsertOrganizationMembership" attempt 1] DBStats beforeRun: sql.DBStats{MaxOpenConnections:1, OpenConnections:1, InUse:0, Idle:1, WaitCount:0, WaitDuration:0, MaxIdleClosed:0, MaxIdleTimeClosed:0, MaxLifetimeClosed:0}, afterRun: sql.DBStats{MaxOpenConnections:1, OpenConnections:1, InUse:0, Idle:1, WaitCount:0, WaitDuration:0, MaxIdleClosed:0, MaxIdleTimeClosed:0, MaxLifetimeClosed:0}
 {"metadata":{"emulator":{"name":"dataconnect"},"message":"I0123 16:22:50.776150   24430 executor.go:96] [operation \"UpsertOrganizationMembership\" attempt 1] DBStats beforeRun: sql.DBStats{MaxOpenConnections:1, OpenConnections:1, InUse:0, Idle:1, WaitCount:0, WaitDuration:0, MaxIdleClosed:0, MaxIdleTimeClosed:0, MaxLifetimeClosed:0}, afterRun: sql.DBStats{MaxOpenConnections:1, OpenConnections:1, InUse:0, Idle:1, WaitCount:0, WaitDuration:0, MaxIdleClosed:0, MaxIdleTimeClosed:0, MaxLifetimeClosed:0}\n"}}
[debug] [2025-01-24T00:22:50.776Z] I0123 16:22:50.776202   24430 engine.go:148] [engine.Service /emulator/other-other-dataconnect 465d] ExecuteGraphql UpsertOrganizationMembership: succeeded. 
 {"metadata":{"emulator":{"name":"dataconnect"},"message":"I0123 16:22:50.776202   24430 engine.go:148] [engine.Service /emulator/other-other-dataconnect 465d] ExecuteGraphql UpsertOrganizationMembership: succeeded. \n"}}
[debug] [2025-01-24T00:23:05.715Z] Frontend message Parse
[debug] [2025-01-24T00:23:05.717Z] Backend message ParseComplete
[debug] [2025-01-24T00:23:05.717Z] Filtered out a ReadyForQuery.
[debug] [2025-01-24T00:23:05.717Z] Frontend message Describe
[debug] [2025-01-24T00:23:05.717Z] Backend message ParameterDescriptionMessage
[debug] [2025-01-24T00:23:05.717Z] Backend message RowDescriptionMessage
[debug] [2025-01-24T00:23:05.717Z] Filtered out a ReadyForQuery.
[debug] [2025-01-24T00:23:05.717Z] Frontend message Sync
[debug] [2025-01-24T00:23:05.718Z] Backend message ReadyForQuery
[debug] [2025-01-24T00:23:05.718Z] I0123 16:23:05.718166   24430 prepare.go:112] [operation "GetOrganizationById" attempt 1] preparePlan succeeded
 {"metadata":{"emulator":{"name":"dataconnect"},"message":"I0123 16:23:05.718166   24430 prepare.go:112] [operation \"GetOrganizationById\" attempt 1] preparePlan succeeded\n"}}
[debug] [2025-01-24T00:23:05.718Z] I0123 16:23:05.718205   24430 prepare.go:103] [operation "GetOrganizationById" attempt 1] DBStats beforePrepare: sql.DBStats{MaxOpenConnections:1, OpenConnections:1, InUse:0, Idle:1, WaitCount:0, WaitDuration:0, MaxIdleClosed:0, MaxIdleTimeClosed:0, MaxLifetimeClosed:0}, afterPrepare: sql.DBStats{MaxOpenConnections:1, OpenConnections:1, InUse:0, Idle:1, WaitCount:0, WaitDuration:0, MaxIdleClosed:0, MaxIdleTimeClosed:0, MaxLifetimeClosed:0}
 {"metadata":{"emulator":{"name":"dataconnect"},"message":"I0123 16:23:05.718205   24430 prepare.go:103] [operation \"GetOrganizationById\" attempt 1] DBStats beforePrepare: sql.DBStats{MaxOpenConnections:1, OpenConnections:1, InUse:0, Idle:1, WaitCount:0, WaitDuration:0, MaxIdleClosed:0, MaxIdleTimeClosed:0, MaxLifetimeClosed:0}, afterPrepare: sql.DBStats{MaxOpenConnections:1, OpenConnections:1, InUse:0, Idle:1, WaitCount:0, WaitDuration:0, MaxIdleClosed:0, MaxIdleTimeClosed:0, MaxLifetimeClosed:0}\n"}}
[debug] [2025-01-24T00:23:05.719Z] Frontend message Query
[debug] [2025-01-24T00:23:05.719Z] Backend message CommandComplete
[debug] [2025-01-24T00:23:05.719Z] Backend message ReadyForQuery
[debug] [2025-01-24T00:23:05.720Z] Frontend message Bind
[debug] [2025-01-24T00:23:05.721Z] Backend message BindComplete
[debug] [2025-01-24T00:23:05.721Z] Filtered out a ReadyForQuery.
[debug] [2025-01-24T00:23:05.721Z] Frontend message Execute
[debug] [2025-01-24T00:23:05.722Z] Backend message DataRow
[debug] [2025-01-24T00:23:05.722Z] Backend message CommandComplete
[debug] [2025-01-24T00:23:05.722Z] Filtered out a ReadyForQuery.
[debug] [2025-01-24T00:23:05.723Z] Frontend message Sync
[debug] [2025-01-24T00:23:05.723Z] Backend message ReadyForQuery
[debug] [2025-01-24T00:23:05.731Z] Frontend message Terminate
[debug] [2025-01-24T00:23:05.732Z] Postgres client disconnected
[debug] [2025-01-24T00:23:05.733Z] I0123 16:23:05.731443   24430 executor.go:96] [operation "GetOrganizationById" attempt 1] DBStats beforeRun: sql.DBStats{MaxOpenConnections:1, OpenConnections:1, InUse:0, Idle:1, WaitCount:0, WaitDuration:0, MaxIdleClosed:0, MaxIdleTimeClosed:0, MaxLifetimeClosed:0}, afterRun: sql.DBStats{MaxOpenConnections:1, OpenConnections:0, InUse:0, Idle:0, WaitCount:0, WaitDuration:0, MaxIdleClosed:0, MaxIdleTimeClosed:0, MaxLifetimeClosed:0}
W0123 16:23:05.732271   24430 engine.go:152] [engine.Service /emulator/other-other-dataconnect 465d] ExecuteGraphql GetOrganizationById: failed. 
Auth: admin impersonating user of {"UID":"joey","Token":{"email_verified":true,"sub":"joey"}}
Variables:
{
   "organizationId": "68a8d1fe-69d9-4983-b4cc-8afa18bd0084"
 }
Errors: input: cannot commit transaction: pq: unexpected transaction status idle

Data:
[123 10 32 32 32 34 111 114 103 97 110 105 122 97 116 105 111 110 34 58 32 123 10 32 32 32 32 32 34 111 114 103 97 110 105 122 97 116 105 111 110 77 101 109 98 101 114 115 104 105 112 115 95 111 110 95 111 114 103 97 110 105 122 97 116 105 111 110 34 58 32 91 10 32 32 32 32 32 32 32 123 10 32 32 32 32 32 32 32 32 32 34 117 105 100 34 58 32 34 106 111 101 121 34 10 32 32 32 32 32 32 32 125 10 32 32 32 32 32 93 44 10 32 32 32 32 32 34 116 105 116 108 101 34 58 32 34 106 111 101 34 10 32 32 32 125 10 32 125]
sources: input [261B] 
 {"metadata":{"emulator":{"name":"dataconnect"},"message":"I0123 16:23:05.731443   24430 executor.go:96] [operation \"GetOrganizationById\" attempt 1] DBStats beforeRun: sql.DBStats{MaxOpenConnections:1, OpenConnections:1, InUse:0, Idle:1, WaitCount:0, WaitDuration:0, MaxIdleClosed:0, MaxIdleTimeClosed:0, MaxLifetimeClosed:0}, afterRun: sql.DBStats{MaxOpenConnections:1, OpenConnections:0, InUse:0, Idle:0, WaitCount:0, WaitDuration:0, MaxIdleClosed:0, MaxIdleTimeClosed:0, MaxLifetimeClosed:0}\nW0123 16:23:05.732271   24430 engine.go:152] [engine.Service /emulator/other-other-dataconnect 465d] ExecuteGraphql GetOrganizationById: failed. \nAuth: admin impersonating user of {\"UID\":\"joey\",\"Token\":{\"email_verified\":true,\"sub\":\"joey\"}}\nVariables:\n{\n   \"organizationId\": \"68a8d1fe-69d9-4983-b4cc-8afa18bd0084\"\n }\nErrors: input: cannot commit transaction: pq: unexpected transaction status idle\n\nData:\n[123 10 32 32 32 34 111 114 103 97 110 105 122 97 116 105 111 110 34 58 32 123 10 32 32 32 32 32 34 111 114 103 97 110 105 122 97 116 105 111 110 77 101 109 98 101 114 115 104 105 112 115 95 111 110 95 111 114 103 97 110 105 122 97 116 105 111 110 34 58 32 91 10 32 32 32 32 32 32 32 123 10 32 32 32 32 32 32 32 32 32 34 117 105 100 34 58 32 34 106 111 101 121 34 10 32 32 32 32 32 32 32 125 10 32 32 32 32 32 93 44 10 32 32 32 32 32 34 116 105 116 108 101 34 58 32 34 106 111 101 34 10 32 32 32 125 10 32 125]\nsources: input [261B] \n"}}

@joehan
Copy link
Contributor

joehan commented Jan 24, 2025

Ok, we've got a few fixes incoming for this:

1 - #8137 should fix the emualtor falling into a broken state and returning prepared statement errors
2 - Within the data connect emulator, we've got a fix that stops using transactions for this type of query - there's only a single SQL statement, so an explicit transaction is pointless.

After 1 and 2, this issue should no longer occur

3 - (TODO: @joehan) The underlying issue here is improper handling of single statement transactions. For the sake of correctness, I'm working on a fix here too.

@joehan joehan self-assigned this Jan 24, 2025
@zmullett
Copy link
Author

LGTM! Thanks for prioritizing this.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
emulator: dataconnect Issues related to the dataconnect emulator type: bug
Projects
None yet
Development

No branches or pull requests

3 participants