pq: operator does not exist: character varying =?

[haf]

Describe the bug

After installing and migrating, and then having trouble with redirects+CORS, I decided to add jaeger. This may or may not have something to do with the bug, but after reconfiguring Hydra to use the deployed Jaeger instance, I got this error:

time="2019-06-02T17:49:13Z" level=fatal msg="Could not ensure that signing keys for \"hydra.openid.id-token\" exists. This can happen if you forget to run \"hydra migrate sql\", set the wrong \"secrets.system\" or forget to set \"secrets.system\" entirely." error="pq: operator does not exist: character varying =?"

causing Hydra to crash.

Not sure how to reproduce; it happened after a configuration change.

Server logs

k logs hydra-8fc46c66-rvt8k
time="2019-06-02T17:59:59Z" level=info msg="Jaeger tracer configured!"
time="2019-06-02T17:59:59Z" level=info msg="Connecting with postgres://*:*@auth-postgres:5432/auth?sslmode=disable"
time="2019-06-02T17:59:59Z" level=info msg="Connected to SQL!"
time="2019-06-02T17:59:59Z" level=fatal msg="Could not ensure that signing keys for \"hydra.openid.id-token\" exists. This can happen if you forget to run \"hydra migrate sql\", set the wrong \"secrets.system\" or forget to set \"secrets.system\" entirely." error="pq: operator does not exist: character varying =?"

Server configuration

      - name: hydra
        image: oryd/hydra:v1.0.0-rc.14
        args:
        - serve
        - all
        - --dangerous-force-http

        env:
        - name: DSN
          value: postgres://auth:xxxxxx@auth-postgres:5432/auth?sslmode=disable&max_conns=20&max_idle_conns=4

        - name: URLS_SELF_ISSUER
          value: https://app.test
        - name: URLS_CONSENT
          value: http://localhost:3000/accounts/consent
        - name: URLS_LOGIN
          value: http://localhost:3000/accounts/login
        - name: URLS_LOGOUT
          value: http://localhost:3000/accounts/logout

        - name: SECRETS_SYSTEM
          valueFrom:
            secretKeyRef:
              key: systemKey
              name: hydra
        - name: SECRETS_COOKIE
          valueFrom:
            secretKeyRef:
              key: cookieKey
              name: hydra

        - name: OIDC_SUBJECT_IDENTIFIERS_ENABLED
          value: public,pairwise
        - name: OIDC_SUBJECT_IDENTIFIERS_PAIRWISE_SALT
          value: xxxxxxxxxx

        - name: SERVE_TLS_ALLOW_TERMINATION_FROM
          value: 10.0.0.0/8
        - name: SERVE_PUBLIC_CORS_ENABLED
          value: "true"
        - name: SERVE_PUBLIC_CORS_ALLOWED_ORIGINS
          value: "https://app.test,http://localhost:3000,http://localhost:5000,http://127.0.0.1:3000,http://127.0.0.1:5000"
        - name: SERVE_PUBLIC_CORS_DEBUG
          value: "true"

        - name: TRACING_PROVIDER
          value: jaeger
        - name: TRACING_PROVIDERS_JAEGER_SAMPLING_SERVER_URL
          value: http://jaeger-agent.monitoring:5778/sampling
        - name: TRACING_PROVIDERS_JAEGER_LOCAL_AGENT_ADDRESS
          value: jaeger-agent.monitoring:6831
        - name: TRACING_PROVIDERS_JAEGER_SAMPLING_TYPE
          value: const
        - name: TRACING_PROVIDERS_JAEGER_SAMPLING_VALUE
          value: "1"

        - name: SQA_OPT_OUT
          value: "true"

---

apiVersion: "apps/v1beta1"
kind: StatefulSet
metadata:
  name: auth-postgres
  namespace: auth

  labels:
    app: auth
    tier: db
    component: postgres

spec:
  serviceName: auth-postgres

  selector:
    matchLabels:
      app: auth
      tier: db
      component: postgres

  replicas: 1

  template: # pod template
    metadata:
      labels:
        app: auth
        tier: db
        component: postgres

    spec:
      containers:
      - name: postgres
        image: postgres:9
        env:
        - name: POSTGRES_DB
          value: auth
        - name: POSTGRES_USER
          value: auth
        - name: POSTGRES_PASSWORD
          valueFrom:
            secretKeyRef:
              key: dbPassword
              name: hydra

        ports:
        - name: pgsql
          containerPort: 5432
          protocol: TCP

        volumeMounts:
        - mountPath: /var/lib/postgresql
          name: data

      volumes:
      - name: data
        persistentVolumeClaim:
          claimName: hydra-postgres

---

apiVersion: batch/v1
kind: Job
metadata:
  name: hydra-migrate
  namespace: auth

  labels:
    app: auth
    tier: db
    component: hydra-migrate

spec:
  template:
    spec:
      containers:
      - name: hydra
        image: oryd/hydra:v1.0.0-rc.14
        args:
        - migrate
        - sql
        - -e
        - --yes
        env:
        - name: DSN
          value: postgres://auth:xxxxxxxxxxx@auth-postgres:5432/auth?sslmode=disable&max_conns=20&max_idle_conns=4

      restartPolicy: OnFailure

Expected behavior

Hydra should not by its own decide not to start. In prod, this would have caused a huge outage.

Environment

• Environment: k8s

Additional context

Add any other context about the problem here.

[aeneasr]

Please set LOG_LEVEL=debug which includes a stack trace, and post it here - thanks

[haf]

It does not print the stack trace with that variable.

Error is probably this line:

[aeneasr]

What's the postgres version you're running?

[haf]

v9

[aeneasr]

Which version did you upgrade from?

[haf]

I did not. This is a clean dev-only install.

EDIT: going to eat something now. I'll be back in a few hours.

[aeneasr]

Have you tried the quickstart with postgres? Also make sure you have at least PG 9.6+. No tests are failing (connecting to a mysql/pg/cockroach is required for all e2e tests) so it's most likely something in your environment.

[haf]

Yes, I had that and then some working. And then I added tracing and it all crashed.

[aeneasr]

If you disable tracing, does it work again?

[haf]

Yes.

[aeneasr]

Ok, that will help with identifying the issue. Most likely something driver-related.

[shaxbee]

Encountered same issue, seems like invalid placeholder is being used for postgres - '?' instead of '$1'.
Edit: disabling jaeger tracing helped here as well.

[haf]

@shaxbee I don't think it's a problem with using ?, since sqlx.DB.Rebind is used with SelectContext: if err := m.DB.SelectContext(ctx, &ds, m.DB.Rebind("SELECT * FROM hydra_jwk WHERE sid=? ORDER BY created_at DESC"), set); err != nil {