Incorrect type inferred, creating invalid and inconsistent jsonb values

[coreyward]

I am experiencing a few bugs related to the format of a value inserted into a JSONB column varying. The results are non-deterministic—I can run the same query with the same values back to back, and it only occasionally winds up formatted differently.

In one bug, the value (a nested JS object) is stringified before insertion into the column as an escaped string (e.g., "{\"foo\": \"bar\"}"). The query for this is pretty simple. INSERT INTO my_table ${sql(data)} RETURNING id. This is happening about 3% of the time.

In another I'm doing a merge with an existing object value and it's winding up an array somehow. This is happening less often—about 0.1% of the time. The SQL query for this is again relatively simple, leaning on sql to do the heavy lifting:

UPDATE users
SET metadata = metadata || ${sql.json(data)}
WHERE id = ${id}

Since I don't know where this is coming from and it's so infrequent it is hard to put together a reproduction, but I am using Zod to parse and validate all inputs before they're passed to sql, so I am reasonably sure that it is not merely the input being in the wrong format (e.g., no typeof value === "object" letting arrays slip through).

If there are any things I can do to capture additional information or avoid this even without fully knowing what is happening I am all ears. 🤞 🙏

[coreyward]

Okay, I did some additional digging and I am more confident that this is actually an issue with this library.

With an initial value in my metadata column of {}, passing a value like { source: "website", foo: "bar" }, and then another like { hello: ["hi", "hola"] } to the function that runs the code shown above is resulting in values in the database like this:

[
  {
  },
  "{\"source\":\"website\",\"foo\":\"bar\"}",
  {
    "hello": [
      "hi",
      "hola"
    ]
  }
]

I also tried updating the sql.json(data) call to sql.typed(data, 3802) to no avail—the same issue still happens occasionally.

I suspect that this is coming down to the wrong type being inferred by the library, resulting in an undesirable cast happening before the query is run, but I don't quite understand how to alter/predict that behavior. Part of what is driving this suspicion is that I am running in a serverless environment with semi-ephemeral connections, and these issues are happening in bursts—I'll get ~3 rows mangled in a 60 second period, and then not again for 20+ minutes.

[porsager]

You shouldn't use the sql.json() helper unless you used pre v3 of postgres and know the reasons 😊 It is deprecated, and json is handled implicitly.

Try to remove the use of sql.json

[coreyward]

@porsager I replaced it with sql.typed(data, 3802) and have the same issue, and I have the issue even when doing sql(data) in the first query (i.e., this is happening when I am not using sql.json too). What would I use instead for cases where I do need it? Doing sql(data) results in it being treated as columns.

[coreyward]

I am manually fixing invalid rows in a production database that are causing errors (a few new ones every hour). I've tried everything I can think of to make this work, but I'm at the point that I'm considering migrating the codebase to Slonik, which is not an inconsiderable amount of work. I've tried looking through the code, but I don't have a great grasp of how the connection with Postgres works, which seems to be at the root of the issue. So if you have any concrete suggestions or explanations for what is happening other than just "don't use this method that you are not using for some queries that still have this issue", I'd appreciate it.

[porsager]

Just pass it raw

sql`insert into test(json) values (${ some_object })`

[porsager]

Sure - just adding what I can considering I'm only on my mobile currently. If you're not able to make a reproducible case it's hard to say where things might go wrong. Are you storing only objects / arrays, or also simple values like string, number, boolean directly?

I use json a lot myself and in other projects, and so do many other users, and I've never heard of a case where same data would some time be saved correctly and some time not. It's probably much more likely you have input values that are sometimes already stringifyed, and some times not. Postgres.js doesn't magically fix that for you, and neither does slonik.

[coreyward]

Just pass it raw

Cool, that works locally, but TypeScript doesn't like it:

const value = { hello: "world" }
const result = await sql`
  insert into test (col) values (${value})
`

Argument of type '{ hello: string; }' is not assignable to parameter of type 'ParameterOrFragment'

In any case, I don't think that'll fix the issue since it's happening with this query as well:

const DecodableInput = z.object({
  objectiveId: ObjectiveId,
  params: z.object({
    // some more fields; happy to share, just trying to be brief
  }),
  content: z.string().trim().min(1).max(2000),
  generated_by: z.string().uuid().optional(),
})
type DecodableInput = z.infer<typeof DecodableInput>

export const storeDecodable = async (input: DecodableInput) => {
  // None of the `input` is user-provided aside from `objectiveId`, which is 
  // validated to be an integer in the specified range (9–109) by the API
  // route handler, again using Zod. `snakecaseKeys` comes from the package
  // named `snakecase-keys`.
  const data = snakecaseKeys(DecodableInput.parse(input), { deep: false })

  const rows = await sql<{ public_id: string }[]>`
    INSERT INTO decodables ${sql(data)}
    RETURNING public_id
  `

  if (rows.length !== 1) {
    throw new Error("Failed to insert decodable")
  }

  return rows[0].public_id
}

Can you tell me more about how this library handles type inference? I am wondering if it's plausible that the database connection (Neon via Vercel Storage) is getting into a bad state when a serverless func has been running for a while.

I have a max_lifetime of 15 seconds configured on the connections—is it possible that there is a race condition causing a stale connection to be used for the type inference that might lead to this? Also wondering how it's determined that a value should be escaped as a JSON object and not a string since jsonb columns allow both.

[coreyward]

I've had a couple instances where two columns on a single row that are saved back to back in the same HTTP request (but separate SQL queries) with disparate values (no relation to one another aside from them both being jsonb cols) were both stored stringified.

The two queries are very different:

UPDATE users
SET ${sql(data)}
WHERE sub = ${sub}

UPDATE users
SET metadata = metadata || ${data}::jsonb
WHERE sub = ${sub}

This seems pretty convincing to me—it's something downstream of a call to sql.

Edit: I've also now been able to trigger this behavior with known, valid input, eliminating some kind of bungled browser input as a possibility.

[coreyward]

For what it's worth, I switched these queries to Slonik as verbatim as possible and the issue has gone away.

[porsager]

Hey @coreyward - sorry for they wait - deadlines at work 😅

I know you might've moved on, but I'd love to dig in if you can give me some leads or a reproducible case. I've looked for any clues, but haven't been able to come close to anything that should cause this, unless it could be related to #392 .

Crossing my fingers you might have a lead for me.

[coreyward]

Hey, appreciate the follow up! It seems plausible that #392 is related, but to be honest, it's a bit over my head. I never experienced the issue locally, just on Vercel, and we have been having networking issues with Vercel’s infrastructure, so it's possible that this only arose as a side effect of complications with that environment. I never did figure out what specific circumstances triggered it, unfortunately. Wish I could do more to help narrow things down, but I don't know what else would be helpful. Do you have any thoughts?

[coreyward]

I just found some cases where this happened on my local Postgres instance with the locally running app, so it seems the complications with networking are unrelated.

[plauclair]

Interesting, we've been having similar issues lately, in our case it did coincide with a pooler change which we thought could be the origin of the issue but the problem is exactly like you describe and I believe one of us has been able to get a similar result with a different connection method, although it is pretty rare (it happens a lot with one, not so much with the other). Will report back if and when I find something that could get to a repro.

If what I describe rings a bell do let me know if there are areas I should poke around first.

[plauclair]

Been poking a bit. Somehow calling describe() between every call makes the problem disappear.

Things I tried as well:

• Adding long (5s) arbitrary waits between calls -> no change
• Removing dependent queries -> no change

1  // Simplified example, entry data is an object, one of the fields is an object that maps to jsonb
2  for (const entryData of entries) {
3    const insertedId = await sql`INSERT INTO x ${sql(entryData)} ON CONFLICT ... RETURNING id`;
4    // Same query. Adding this makes query on line 3 work 100% of the time.
5    const sql`/* same query */`.describe()
6    if (insertedId) { /* run dependent queries */ }
7  }

This is the describe output:

{
  string: '\n' +
    '        INSERT INTO redacted ("[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]")values($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12,$13,$14,$15,$16,$17,$18,$19,$20,$21,$22) ON CONFLICT (notion_page_id) DO UPDATE SET "[redacted]"=$23,"[redacted]"=$24,"[redacted]"=$25,"[redacted]"=$26,"[redacted]"=$27,"[redacted]"=$28,"[redacted]"=$29,"[redacted]"=$30,"[redacted]"=$31,"[redacted]"=$32,"[redacted]"=$33,"[redacted]"=$34,"[redacted]"=$35,"[redacted]"=$36,"[redacted]"=$37,"[redacted]"=$38,"[redacted]"=$39,"[redacted]"=$40,"[redacted]"=$41,"[redacted]"=$42,"[redacted]"=$43,"[redacted]"=$44 RETURNING id;\n' +
    '    ',
  types: [
       25,    25, 1009,   21, 2950, 1009,   25,
       25,   700,  700,  700,  700,  700,  700,
      700,  1114,   25,   16,   25,   25, 3802,
    33169,    25,   25, 1009,   21, 2950, 1009,
       25,    25,  700,  700,  700,  700,  700,
      700,   700, 1114,   25,   16,   25,   25,
     3802, 33169
  ],
  name: 'ddt65elbngj45',
  columns: [
    {
      name: 'id',
      parser: undefined,
      table: 30956,
      number: 1,
      type: 2950
    }
  ]
}

[plauclair]

And this is the .statement for a good and a bad insert. In both cases, the types are 3082 ($21, $42)

// OK insert
typeof problematic_column: object
{
  string: '\n' +
    '        INSERT INTO table ("[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[problematic_column]","[redacted]")values($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12,$13,$14,$15,$16,$17,$18,$19,$20,$21,$22) ON CONFLICT (notion_page_id) DO UPDATE SET "[redacted]"=$23,"[redacted]"=$24,"[redacted]"=$25,"[redacted]"=$26,"[redacted]"=$27,"[redacted]"=$28,"[redacted]"=$29,"[redacted]"=$30,"[redacted]"=$31,"[redacted]"=$32,"[redacted]"=$33,"[redacted]"=$34,"[redacted]"=$35,"[redacted]"=$36,"[redacted]"=$37,"[redacted]"=$38,"[redacted]"=$39,"[redacted]"=$40,"[redacted]"=$41,"[redacted]"=$42,"[problematic_column]"=$43,"[redacted]"=$44 RETURNING id;\n' +
    '    ',
  types: [
       25,    25, 1009,   21, 2950, 1009,   25,
       25,   700,  700,  700,  700,  700,  700,
      700,  1114,   25,   16,   25,   25, 3802,
    33169,    25,   25, 1009,   21, 2950, 1009,
       25,    25,  700,  700,  700,  700,  700,
      700,   700, 1114,   25,   16,   25,   25,
     3802, 33169
  ],
  name: 'gvtpd98nkuo8',
  columns: [
    {
      name: 'id',
      parser: undefined,
      table: 30956,
      number: 1,
      type: 2950
    }
  ]
}
typeof problematic_column when read from select: object

// Bad insert
typeof problematic_column: object
{
  string: '\n' +
    '        INSERT INTO table ("[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[redacted]","[problematic_column]","[redacted]")values($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12,$13,$14,$15,$16,$17,$18,$19,$20,$21,$22) ON CONFLICT (notion_page_id) DO UPDATE SET "[redacted]"=$23,"[redacted]"=$24,"[redacted]"=$25,"[redacted]"=$26,"[redacted]"=$27,"[redacted]"=$28,"[redacted]"=$29,"[redacted]"=$30,"[redacted]"=$31,"[redacted]"=$32,"[redacted]"=$33,"[redacted]"=$34,"[redacted]"=$35,"[redacted]"=$36,"[redacted]"=$37,"[redacted]"=$38,"[redacted]"=$39,"[redacted]"=$40,"[redacted]"=$41,"[redacted]"=$42,"[problematic_column]"=$43,"[redacted]"=$44 RETURNING id;\n' +
    '    ',
  types: [
       25,    25, 1009,   21, 2950, 1009,   25,
       25,   700,  700,  700,  700,  700,  700,
      700,  1114,   25,   16,   25,   25, 3802,
    33169,    25,   25, 1009,   21, 2950, 1009,
       25,    25,  700,  700,  700,  700,  700,
      700,   700, 1114,   25,   16,   25,   25,
     3802, 33169
  ],
  name: 'gvtpd98nkuo17',
  columns: [
    {
      name: 'id',
      parser: undefined,
      table: 30956,
      number: 1,
      type: 2950
    }
  ]
}
typeof problematic_column when read from select: string

[plauclair]

Finally, it seems that setting the client prepare option to false fixes it.

We don't manage the DB so I have limited details in the configuration, it's using https://github.com/supabase/supavisor as a pooler, and the one that fails less is on PgBouncer, both on Supabase. I just realized it does indeed run in transaction mode, so maybe that's what @coreyward was experiencing as well. Docs say PgBouncer can be made to support it but I don't know if theirs does. Supavisor just doesn't mention it.

Now, I don't know enough about Postgres connections to understand if that means the issue is in the pooler and I should open an issue there, or if it's on the query side. Thoughts?

[porsager]

That is some very nice debugging @plauclair ! I think you are on to something with regards to the poolers, but normally pgbouncer will complain if trying to use named prepared statements when it is running in transaction mode. ( https://github.com/porsager/postgres#prepared-statements )

[plauclair]

That's what I thought as well, so this is a bit surprising.

I'm wondering if maybe they aren't using a custom fork of PgBouncer introducing unexpected behavior.

Right now, I don't have a reason to suspect your library to be the cause of this issue. 👍

[porsager]

If there are any news in this case, feel free to reopen.