Bump to duckdb main and plug DuckDB own logging

[carlopi]

Changes:

• bump to duckdb v1.5-variegata
• restore Integration tests CI run
• pass around ClientContext from various callsites down the stack
• add a new log type: PostgresQueryLog
• add DUCKDB_LOGs, logging query (or queries) and duration in ms

Second step, that is passing around ClientContext &context changing a lot of signatures I am less sure, it can probably be reworked, open to feedback.

All in all, this allows for example:

CALL enable_logging(level=trace);
ATTACH 'ducklake:postgres:postgresql:<...>' as ducklake;
CREATE OR REPLACE SECRET secret (TYPE s3, <...>);
FROM ducklake.some_table;
FROM ducklake.some_table;
FROM ducklake.some_table;
FROM duckdb_logs_parsed('PostgresQueryLog');

Here we are attaching to a ducklake backed by Postgres, and run some queries.

┌────────────┬────────────┬───────────────┬────────────────┬──────────┬───────────┬──────────────────────┬──────────────────┬───────────┬─────────────────────────────────────────────────────────┬─────────────┐
│ context_id │   scope    │ connection_id │ transaction_id │ query_id │ thread_id │      timestamp       │       type       │ log_level │                          query                          │ duration_ms │
│   uint64   │  varchar   │    uint64     │     uint64     │  uint64  │  uint64   │ timestamp with tim…  │     varchar      │  varchar  │                         varchar                         │    int64    │
├────────────┼────────────┼───────────────┼────────────────┼──────────┼───────────┼──────────────────────┼──────────────────┼───────────┼─────────────────────────────────────────────────────────┼─────────────┤
│         34 │ CONNECTION │             3 │              8 │        9 │      NULL │ 2025-11-22 18:25:1…  │ PostgresQueryLog │ DEBUG     │ SELECT version(), (SELECT COUNT(*) FROM pg_settings W…  │         134 │
│         42 │ CONNECTION │             3 │              8 │       11 │      NULL │ 2025-11-22 18:25:1…  │ PostgresQueryLog │ DEBUG     │ BEGIN TRANSACTION ISOLATION LEVEL REPEATABLE READ;\n\…  │         602 │
│         42 │ CONNECTION │             3 │              8 │       11 │      NULL │ 2025-11-22 18:25:1…  │ PostgresQueryLog │ DEBUG     │ \nSELECT pg_namespace.oid AS namespace_id, relname, r…  │         108 │
│         42 │ CONNECTION │             3 │              8 │       11 │      NULL │ 2025-11-22 18:25:1…  │ PostgresQueryLog │ DEBUG     │ \nSELECT pg_namespace.oid AS namespace_id, relname, r…  │         108 │
│         42 │ CONNECTION │             3 │              8 │       11 │      NULL │ 2025-11-22 18:25:1…  │ PostgresQueryLog │ DEBUG     │ \nSELECT pg_namespace.oid AS namespace_id, relname, r…  │         108 │
│         47 │ CONNECTION │             3 │              8 │       12 │      NULL │ 2025-11-22 18:25:1…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "key", "value", "scope", "scope_id" FROM…  │         108 │
│         52 │ CONNECTION │             3 │              8 │       13 │      NULL │ 2025-11-22 18:25:1…  │ PostgresQueryLog │ DEBUG     │ COMMIT                                                  │         106 │
│         67 │ CONNECTION │             4 │             11 │       17 │      NULL │ 2025-11-22 18:25:2…  │ PostgresQueryLog │ DEBUG     │ BEGIN TRANSACTION ISOLATION LEVEL REPEATABLE READ       │         113 │
│         67 │ CONNECTION │             4 │             11 │       17 │      NULL │ 2025-11-22 18:25:2…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "snapshot_id", "schema_version", "next_c…  │         111 │
│         71 │ CONNECTION │             4 │             11 │       18 │      NULL │ 2025-11-22 18:25:2…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "begin_snapshot", "end_snapshot", "schem…  │         520 │
│         75 │ CONNECTION │             4 │             11 │       19 │      NULL │ 2025-11-22 18:25:2…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "table_id", "begin_snapshot", "end_snaps…  │         163 │
│         75 │ CONNECTION │             4 │             11 │       19 │      NULL │ 2025-11-22 18:25:2…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "table_id", "begin_snapshot", "end_snaps…  │         108 │
│         75 │ CONNECTION │             4 │             11 │       19 │      NULL │ 2025-11-22 18:25:2…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "object_id", "begin_snapshot", "end_snap…  │         140 │
│         75 │ CONNECTION │             4 │             11 │       19 │      NULL │ 2025-11-22 18:25:2…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "table_id", "table_name", "schema_versio…  │         107 │
│         75 │ CONNECTION │             4 │             11 │       19 │      NULL │ 2025-11-22 18:25:2…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "table_id", "column_id", "begin_snapshot…  │         108 │
│        198 │ CONNECTION │             4 │             11 │       20 │      NULL │ 2025-11-22 18:25:2…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "begin_snapshot", "end_snapshot", "view_…  │         107 │
│        198 │ CONNECTION │             4 │             11 │       20 │      NULL │ 2025-11-22 18:25:2…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "object_id", "begin_snapshot", "end_snap…  │         184 │
│        210 │ CONNECTION │             4 │             11 │       21 │      NULL │ 2025-11-22 18:25:2…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "partition_id", "begin_snapshot", "end_s…  │         107 │
│        210 │ CONNECTION │             4 │             11 │       21 │      NULL │ 2025-11-22 18:25:2…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "partition_id", "partition_key_index", "…  │         108 │
│        217 │ CONNECTION │             4 │             11 │       22 │      NULL │ 2025-11-22 18:25:2…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "table_id", "record_count", "file_size_b…  │         110 │
│        217 │ CONNECTION │             4 │             11 │       22 │      NULL │ 2025-11-22 18:25:2…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "table_id", "column_id", "contains_null"…  │         108 │
│        239 │ CONNECTION │             4 │             11 │       23 │      NULL │ 2025-11-22 18:25:2…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "data_file_id", "table_id", "begin_snaps…  │         191 │
│        239 │ CONNECTION │             4 │             11 │       23 │      NULL │ 2025-11-22 18:25:2…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "table_id", "begin_snapshot", "end_snaps…  │         109 │
│        247 │ CONNECTION │             4 │             11 │       24 │      NULL │ 2025-11-22 18:25:2…  │ PostgresQueryLog │ DEBUG     │ COMMIT                                                  │         107 │
│        258 │ CONNECTION │             5 │             13 │       27 │      NULL │ 2025-11-22 18:25:3…  │ PostgresQueryLog │ DEBUG     │ BEGIN TRANSACTION ISOLATION LEVEL REPEATABLE READ       │         132 │
│        258 │ CONNECTION │             5 │             13 │       27 │      NULL │ 2025-11-22 18:25:3…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "snapshot_id", "schema_version", "next_c…  │         200 │
│        274 │ CONNECTION │             5 │             13 │       28 │      NULL │ 2025-11-22 18:25:3…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "data_file_id", "table_id", "begin_snaps…  │         107 │
│        274 │ CONNECTION │             5 │             13 │       28 │      NULL │ 2025-11-22 18:25:3…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "table_id", "begin_snapshot", "end_snaps…  │         107 │
│        283 │ CONNECTION │             5 │             13 │       29 │      NULL │ 2025-11-22 18:25:3…  │ PostgresQueryLog │ DEBUG     │ COMMIT                                                  │         107 │
│        294 │ CONNECTION │             6 │             15 │       32 │      NULL │ 2025-11-22 18:25:3…  │ PostgresQueryLog │ DEBUG     │ BEGIN TRANSACTION ISOLATION LEVEL REPEATABLE READ       │         180 │
│        294 │ CONNECTION │             6 │             15 │       32 │      NULL │ 2025-11-22 18:25:3…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "snapshot_id", "schema_version", "next_c…  │         106 │
│        311 │ CONNECTION │             6 │             15 │       33 │      NULL │ 2025-11-22 18:25:3…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "data_file_id", "table_id", "begin_snaps…  │         108 │
│        311 │ CONNECTION │             6 │             15 │       33 │      NULL │ 2025-11-22 18:25:3…  │ PostgresQueryLog │ DEBUG     │ COPY (SELECT "table_id", "begin_snapshot", "end_snaps…  │         107 │
│        319 │ CONNECTION │             6 │             15 │       34 │      NULL │ 2025-11-22 18:25:3…  │ PostgresQueryLog │ DEBUG     │ COMMIT                                                  │         106 │
├────────────┴────────────┴───────────────┴────────────────┴──────────┴───────────┴──────────────────────┴──────────────────┴───────────┴─────────────────────────────────────────────────────────┴─────────────┤
│ 34 rows                                                                                                                                                                                            11 columns │
└───────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┘

This could allowing a faster feedback cycle: directly from SQL, debug what interactions (and how much latency they bring) are required on the underlying Postgres database. This allows both users to tweak / understand how heavy are certain queries, and developers to get feedback and optimize them.

[carlopi]

Failure is legit, PostgresTransaction outlives ClientContext, and so GetContext() call gives out a nonsensical result.

Solutions:

1. change duckdb::Transaction from have a weak_ptr to have shared_ptr<ClientContext> (this has been validated to fix the issue here
2. change signature of GetContext() to return optional_ptr, and check that on usage

Problem on 1 is that requires changes in core, and might change behaviour of what happens at the border (say in destructors). Problem on 2 is that some transactions will not be logged.

[carlopi]

I went for path 2, since can be implemented only duckdb-postgres side, but note that some queries (most likely COMMIT / ROLLBACK) might happen during teardown, so without a ClientContext available.

[carlopi]

@Mytherin: main risk is this changing a bunch of signatures, but should be sort of OK. Not really urgent.

[Mytherin]

Looks fine to me but let's merge it into the branch for v1.5

[guillesd]

@pdet if you can take a look, this would help DuckLake debugging a lot, particularly now that we want to optimize performance for postgres

[carlopi]

Maybe we just need to branch (off current main) a v1.4-andium branch, and then merge this into the main branch (pointing to some relevant commit).

I guess this would still be needed at some later point, LTS vs main, so can as well be done in advance, but I am fine with whatever timeline. Let me know if I need to change the PR somehow (even retargeting to a different duckdb commit).

[carlopi]

Retargeted to recent duckdb (last night), applied patch

[guillesd]

@carlopi is this going to go into 1.5?

[pdet]

I think the PR looks great, I don't have any major comments. Is mostly signature changes , which are necessary since all these methods are static. Only thing I'm missing is a test.

[carlopi]

Added test, and restored integration tests. This should be passing CI, and so ready to land.

[Mytherin]

Thanks!