Aurora Serverless V2 PostgreSQL 15.2 database - unrecognized node type 380

Get Help
1

We have been using Metabase for years talking to RDS PostgreSQL 12.11 instances using the Elastic Beanstalk (ELB) setup in AWS. Recently we upgraded to RDS PostgreSQL 15.2 instances, and Metabase continued working fine, no errors.

But then upgrading to Aurora PostgreSQL compatible 15.2 instances running Serverless v2, suddenly we get errors in the PostgreSQL instance logs. No errors in the Metabase logs though, but the errors are definitely driven by Metabase.

When resyncing the database schema for an ASv2 instance we get the following in the instance PostgreSQL logs (x's are obfuscated stuff, ignore):

2023-06-19 23:31:03 UTC:xxx.xxx.xxx.xxx(36056):xxxx@xxxx:[32275]:warning: unrecognized node type: 380

This throws multiple times per each table, it seems. For a prod database with a hundred tables we see this a few hundred times in the logs mostly while it's performing the "fingerprint fields" operation, but also on some others.

We were using an older Metabase version (0.36.5) but I just upgraded a clone of that ELB environment to the latest version (0.46.5) as well as upgrading the underlying Docker version of the ELB instance to 3.8.5.

From what I can see the data in Metabase is accurate after these syncs, even though that warning is thrown hundreds of times. Curious if there's any idea what's causing it? Seems easy to reproduce as if you create a new database using Aurora Serverless v2 and PostgreSQL compatible, scanning the instance's postgres database once it comes online before even creating any tables (so there's nothing in it at all!) throws these warnings.

I will note we're still running the actual Metabase RDS database as PostgreSQL 12.11, provisioned RDS. But I wouldn't expect that would matter.

Any suggestions would be great! Or even just a "this is not impactful due to x and y" so we can go on with our day lol.

Thank you!
Mike

2

We used serverless for some time and we moved back to provisioned instances. The only thing we saw was that the auto incremental ids jumped by 30

3

I just tested and this same thing happens on a fresh unmodified Aurora Provisioned cluster as well (PostgreSQL 15.2).

Any suggestion how we might figure out what it's trying to do that Aurora can't seem to handle? Short of enabling statement logging for everything and running another sync.

4

Actually just ran that setup, statement logging set to all rebooted the DB and nothing else connecting to it (no data in the DB besides the public schema on the default postgres empty DB) and clicked "Sync database schema now" button in Metabase:

2023-06-20 16:38:08 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:LOG: execute <unnamed>: SET extra_float_digits = 3
2023-06-20 16:38:08 UTC:x.xx.xxx.xxx(41164):postgres@postgres:[657]:LOG: execute <unnamed>: SET extra_float_digits = 3
2023-06-20 16:38:08 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:LOG: execute <unnamed>: SET application_name = 'Metabase v0.46.5 [ec32db87-958e-4dfa-8246-38be7319b765]'
2023-06-20 16:38:08 UTC:x.xx.xxx.xxx(41164):postgres@postgres:[657]:LOG: execute <unnamed>: SET application_name = 'Metabase v0.46.5 [ec32db87-958e-4dfa-8246-38be7319b765]'
2023-06-20 16:38:08 UTC:x.xx.xxx.xxx(41164):postgres@postgres:[657]:LOG: execute <unnamed>: SHOW TRANSACTION ISOLATION LEVEL
2023-06-20 16:38:08 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:LOG: execute <unnamed>: SHOW TRANSACTION ISOLATION LEVEL
2023-06-20 16:38:09 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:WARNING: unrecognized node type: 380
2023-06-20 16:38:09 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:LOG: execute <unnamed>: SET SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL READ UNCOMMITTED
2023-06-20 16:38:09 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:LOG: execute <unnamed>: SELECT nspname AS TABLE_SCHEM, NULL AS TABLE_CATALOG FROM pg_catalog.pg_namespace WHERE nspname <> 'pg_toast' AND (nspname !~ '^pg_temp_' OR nspname = (pg_catalog.current_schemas(true))[1]) AND (nspname !~ '^pg_toast_temp_' OR nspname = replace((pg_catalog.current_schemas(true))[1], 'pg_temp_', 'pg_toast_temp_')) ORDER BY TABLE_SCHEM
2023-06-20 16:38:09 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:LOG: execute <unnamed>: SELECT NULL AS TABLE_CAT, n.nspname AS TABLE_SCHEM, c.relname AS TABLE_NAME, CASE n.nspname ~ '^pg_' OR n.nspname = 'information_schema' WHEN true THEN CASE WHEN n.nspname = 'pg_catalog' OR n.nspname = 'information_schema' THEN CASE c.relkind WHEN 'r' THEN 'SYSTEM TABLE' WHEN 'v' THEN 'SYSTEM VIEW' WHEN 'i' THEN 'SYSTEM INDEX' ELSE NULL END WHEN n.nspname = 'pg_toast' THEN CASE c.relkind WHEN 'r' THEN 'SYSTEM TOAST TABLE' WHEN 'i' THEN 'SYSTEM TOAST INDEX' ELSE NULL END ELSE CASE c.relkind WHEN 'r' THEN 'TEMPORARY TABLE' WHEN 'p' THEN 'TEMPORARY TABLE' WHEN 'i' THEN 'TEMPORARY INDEX' WHEN 'S' THEN 'TEMPORARY SEQUENCE' WHEN 'v' THEN 'TEMPORARY VIEW' ELSE NULL END END WHEN false THEN CASE c.relkind WHEN 'r' THEN 'TABLE' WHEN 'p' THEN 'PARTITIONED TABLE' WHEN 'i' THEN 'INDEX' WHEN 'P' then 'PARTITIONED INDEX' WHEN 'S' THEN 'SEQUENCE' WHEN 'v' THEN 'VIEW' WHEN 'c' THEN 'TYPE' WHEN 'f' THEN 'FOREIGN TABLE' WHEN 'm' THEN 'MATERIALIZED VIEW' ELSE NULL END ELSE NULL END AS TABLE_TYPE, d.description AS REMARKS, '' as TYPE_CAT, '' as TYPE_SCHEM, '' as TYPE_NAME, '' AS SELF_REFERENCING_COL_NAME, '' AS REF_GENERATION FROM pg_catalog.pg_namespace n, pg_catalog.pg_class c LEFT JOIN pg_catalog.pg_description d ON (c.oid = d.objoid AND d.objsubid = 0 and d.classoid = 'pg_class'::regclass) WHERE c.relnamespace = n.oid AND n.nspname LIKE 'information_schema' AND c.relname LIKE '%' AND (false OR ( c.relkind = 'r' AND n.nspname !~ '^pg_' AND n.nspname <> 'information_schema' ) OR ( c.relkind = 'p' AND n.nspname !~ '^pg_' AND n.nspname <> 'information_schema' ) OR ( c.relkind = 'v' AND n.nspname <> 'pg_catalog' AND n.nspname <> 'information_schema' ) OR ( c.relkind = 'f' ) OR ( c.relkind = 'm' ) ) ORDER BY TABLE_TYPE,TABLE_SCHEM,TABLE_NAME
2023-06-20 16:38:09 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:LOG: execute <unnamed>: SELECT NULL AS TABLE_CAT, n.nspname AS TABLE_SCHEM, c.relname AS TABLE_NAME, CASE n.nspname ~ '^pg_' OR n.nspname = 'information_schema' WHEN true THEN CASE WHEN n.nspname = 'pg_catalog' OR n.nspname = 'information_schema' THEN CASE c.relkind WHEN 'r' THEN 'SYSTEM TABLE' WHEN 'v' THEN 'SYSTEM VIEW' WHEN 'i' THEN 'SYSTEM INDEX' ELSE NULL END WHEN n.nspname = 'pg_toast' THEN CASE c.relkind WHEN 'r' THEN 'SYSTEM TOAST TABLE' WHEN 'i' THEN 'SYSTEM TOAST INDEX' ELSE NULL END ELSE CASE c.relkind WHEN 'r' THEN 'TEMPORARY TABLE' WHEN 'p' THEN 'TEMPORARY TABLE' WHEN 'i' THEN 'TEMPORARY INDEX' WHEN 'S' THEN 'TEMPORARY SEQUENCE' WHEN 'v' THEN 'TEMPORARY VIEW' ELSE NULL END END WHEN false THEN CASE c.relkind WHEN 'r' THEN 'TABLE' WHEN 'p' THEN 'PARTITIONED TABLE' WHEN 'i' THEN 'INDEX' WHEN 'P' then 'PARTITIONED INDEX' WHEN 'S' THEN 'SEQUENCE' WHEN 'v' THEN 'VIEW' WHEN 'c' THEN 'TYPE' WHEN 'f' THEN 'FOREIGN TABLE' WHEN 'm' THEN 'MATERIALIZED VIEW' ELSE NULL END ELSE NULL END AS TABLE_TYPE, d.description AS REMARKS, '' as TYPE_CAT, '' as TYPE_SCHEM, '' as TYPE_NAME, '' AS SELF_REFERENCING_COL_NAME, '' AS REF_GENERATION FROM pg_catalog.pg_namespace n, pg_catalog.pg_class c LEFT JOIN pg_catalog.pg_description d ON (c.oid = d.objoid AND d.objsubid = 0 and d.classoid = 'pg_class'::regclass) WHERE c.relnamespace = n.oid AND n.nspname LIKE 'pg_catalog' AND c.relname LIKE '%' AND (false OR ( c.relkind = 'r' AND n.nspname !~ '^pg_' AND n.nspname <> 'information_schema' ) OR ( c.relkind = 'p' AND n.nspname !~ '^pg_' AND n.nspname <> 'information_schema' ) OR ( c.relkind = 'v' AND n.nspname <> 'pg_catalog' AND n.nspname <> 'information_schema' ) OR ( c.relkind = 'f' ) OR ( c.relkind = 'm' ) ) ORDER BY TABLE_TYPE,TABLE_SCHEM,TABLE_NAME
2023-06-20 16:38:09 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:LOG: execute <unnamed>: SELECT NULL AS TABLE_CAT, n.nspname AS TABLE_SCHEM, c.relname AS TABLE_NAME, CASE n.nspname ~ '^pg_' OR n.nspname = 'information_schema' WHEN true THEN CASE WHEN n.nspname = 'pg_catalog' OR n.nspname = 'information_schema' THEN CASE c.relkind WHEN 'r' THEN 'SYSTEM TABLE' WHEN 'v' THEN 'SYSTEM VIEW' WHEN 'i' THEN 'SYSTEM INDEX' ELSE NULL END WHEN n.nspname = 'pg_toast' THEN CASE c.relkind WHEN 'r' THEN 'SYSTEM TOAST TABLE' WHEN 'i' THEN 'SYSTEM TOAST INDEX' ELSE NULL END ELSE CASE c.relkind WHEN 'r' THEN 'TEMPORARY TABLE' WHEN 'p' THEN 'TEMPORARY TABLE' WHEN 'i' THEN 'TEMPORARY INDEX' WHEN 'S' THEN 'TEMPORARY SEQUENCE' WHEN 'v' THEN 'TEMPORARY VIEW' ELSE NULL END END WHEN false THEN CASE c.relkind WHEN 'r' THEN 'TABLE' WHEN 'p' THEN 'PARTITIONED TABLE' WHEN 'i' THEN 'INDEX' WHEN 'P' then 'PARTITIONED INDEX' WHEN 'S' THEN 'SEQUENCE' WHEN 'v' THEN 'VIEW' WHEN 'c' THEN 'TYPE' WHEN 'f' THEN 'FOREIGN TABLE' WHEN 'm' THEN 'MATERIALIZED VIEW' ELSE NULL END ELSE NULL END AS TABLE_TYPE, d.description AS REMARKS, '' as TYPE_CAT, '' as TYPE_SCHEM, '' as TYPE_NAME, '' AS SELF_REFERENCING_COL_NAME, '' AS REF_GENERATION FROM pg_catalog.pg_namespace n, pg_catalog.pg_class c LEFT JOIN pg_catalog.pg_description d ON (c.oid = d.objoid AND d.objsubid = 0 and d.classoid = 'pg_class'::regclass) WHERE c.relnamespace = n.oid AND n.nspname LIKE 'public' AND c.relname LIKE '%' AND (false OR ( c.relkind = 'r' AND n.nspname !~ '^pg_' AND n.nspname <> 'information_schema' ) OR ( c.relkind = 'p' AND n.nspname !~ '^pg_' AND n.nspname <> 'information_schema' ) OR ( c.relkind = 'v' AND n.nspname <> 'pg_catalog' AND n.nspname <> 'information_schema' ) OR ( c.relkind = 'f' ) OR ( c.relkind = 'm' ) ) ORDER BY TABLE_TYPE,TABLE_SCHEM,TABLE_NAME
2023-06-20 16:38:09 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:WARNING: unrecognized node type: 380
2023-06-20 16:38:09 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:LOG: execute <unnamed>: SET SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL READ COMMITTED
2023-06-20 16:38:09 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:WARNING: unrecognized node type: 380
2023-06-20 16:38:09 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:LOG: execute <unnamed>: SET SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL READ UNCOMMITTED
2023-06-20 16:38:09 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:LOG: execute <unnamed>: SET SESSION TIMEZONE TO 'UTC'
2023-06-20 16:38:09 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:LOG: execute <unnamed>: BEGIN READ ONLY
2023-06-20 16:38:09 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:LOG: execute <unnamed>/C_1: -- Metabase
select to_char(current_timestamp, 'YYYY-MM-DD HH24:MI:SS.MS TZ')
2023-06-20 16:38:09 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:LOG: execute S_2: ROLLBACK
2023-06-20 16:38:09 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:WARNING: unrecognized node type: 380
2023-06-20 16:38:09 UTC:x.xx.xxx.xxx(41162):postgres@postgres:[656]:LOG: execute <unnamed>: SET SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL READ COMMITTED

This happens on Aurora Provisioned Postgres 15.2 and ServerlessV2.

5

Thanks for checking, seems that’s the only way to check this out. I’m pretty sure that aurora is doing something diverting from the Postgres standard but that’s just a guess

6

Ah, and if one runs each statement individually, this is the one where it's throwing the unrecognized node type 380 error:

SET SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL READ UNCOMMITTED

That said, it DOES set it correctly, like if you do a SHOW TRANSACTION ISOLATION LEVEL after it shows read uncommitted. So this does seem like a false alarm warning, unless there's more going on behind the scenes of this inside Aurora.

7

it's extremely weird that you don't get that error in a plain postgres server :person_shrugging:

8

Yeah, and Aurora's docs show that is a valid command. Maybe it's some magic combo of the newer PostgreSQL release and Aurora's interpretation. We don't run any wacky extensions or many modified parameters (and the parameters we do modify are the same mostly between RDS PostgreSQL and Aurora)

Oh well, we'll call it a day on this one and maybe something will change in the future on it but seems harmless.