[yugabyte#29080] YSQL: add debug log for relcache

Summary:
The stacktrace of the core dump:
```
(lldb) bt all
* thread #1, name = 'postgres', stop reason = signal SIGSEGV: address not mapped to object
  * frame #0: 0x0000aaaac59fb720 postgres`FreeTupleDesc [inlined] GetMemoryChunkContext(pointer=0x0000000000000000) at memutils.h:141:12
    frame #1: 0x0000aaaac59fb710 postgres`FreeTupleDesc [inlined] pfree(pointer=0x0000000000000000) at mcxt.c:1500:26
    frame #2: 0x0000aaaac59fb710 postgres`FreeTupleDesc(tupdesc=0x000013d7fd8dccc8) at tupdesc.c:326:5
    frame #3: 0x0000aaaac61c7204 postgres`RelationDestroyRelation(relation=0x000013d7fd8dc9a8, remember_tupdesc=false) at relcache.c:4577:4
    frame #4: 0x0000aaaac5febab8 postgres`YBRefreshCache at relcache.c:5216:3
    frame #5: 0x0000aaaac5feba94 postgres`YBRefreshCache at postgres.c:4442:2
    frame #6: 0x0000aaaac5feb50c postgres`YBRefreshCacheWrapperImpl(catalog_master_version=0, is_retry=false, full_refresh_allowed=true) at postgres.c:4570:3
    frame #7: 0x0000aaaac5feea34 postgres`PostgresMain [inlined] YBRefreshCacheWrapper(catalog_master_version=0, is_retry=false) at postgres.c:4586:9
    frame #8: 0x0000aaaac5feea2c postgres`PostgresMain [inlined] YBCheckSharedCatalogCacheVersion at postgres.c:4951:3
    frame #9: 0x0000aaaac5fee984 postgres`PostgresMain(dbname=<unavailable>, username=<unavailable>) at postgres.c:6574:4
    frame #10: 0x0000aaaac5efe5b4 postgres`BackendRun(port=0x000013d7ffc06400) at postmaster.c:4995:2
    frame #11: 0x0000aaaac5efdd08 postgres`ServerLoop [inlined] BackendStartup(port=0x000013d7ffc06400) at postmaster.c:4701:3
    frame yugabyte#12: 0x0000aaaac5efdc70 postgres`ServerLoop at postmaster.c:1908:7
    frame yugabyte#13: 0x0000aaaac5ef8ef8 postgres`PostmasterMain(argc=<unavailable>, argv=<unavailable>) at postmaster.c:1562:11
    frame yugabyte#14: 0x0000aaaac5ddae1c postgres`PostgresServerProcessMain(argc=25, argv=0x000013d7ffe068f0) at main.c:213:3
    frame yugabyte#15: 0x0000aaaac59dee38 postgres`main + 36
    frame yugabyte#16: 0x0000ffff9f606340 libc.so.6`__libc_start_call_main + 112
    frame yugabyte#17: 0x0000ffff9f606418 libc.so.6`__libc_start_main@@GLIBC_2.34 + 152
    frame yugabyte#18: 0x0000aaaac59ded34 postgres`_start + 52
```
It is related to invalidation message. The test involves concurrent DDL execution without object
locking.

I added a few logs to help to debug this issue.

Test Plan:
(1)
Append to the end of file ./build/latest/postgres/share/postgresql.conf.sample:

```
yb_debug_log_catcache_events=1
log_min_messages=DEBUG1
```

(2) Create a RF-1 cluster
```
./bin/yb-ctl create --rf 1
```

(3) Run the following example via ysqlsh:
```
-- === 1. SETUP ===
DROP TABLE IF EXISTS accounts_timetravel;
CREATE TABLE accounts_timetravel (
  id INT PRIMARY KEY,
  balance INT,
  last_updated TIMESTAMPTZ
);

INSERT INTO accounts_timetravel VALUES (1, 1000, now());

\echo '--- 1. Initial Data (The Past) ---'
SELECT * FROM accounts_timetravel;

-- Wait 2 seconds
SELECT pg_sleep(2);

-- === 2. CAPTURE THE "PAST" HLC TIMESTAMP ===
--
--    *** THIS IS THE FIX ***
--    Get the current time as seconds from the Unix epoch,
--    multiply by 1,000,000 to get microseconds,
--    and cast to a big integer.
--
SELECT (EXTRACT(EPOCH FROM now())*1000000)::bigint AS snapshot_hlc \gset
SELECT :snapshot_hlc;
\echo '--- (Snapshot HLC captured) ---'

SELECT * FROM pg_yb_catalog_version;

-- Wait 2 more seconds
SELECT pg_sleep(2);

-- === 3. UPDATE THE DATA ===
UPDATE accounts_timetravel SET balance = 500, last_updated = now() WHERE id = 1;

\echo '--- 2. New Data (The Present) ---'
SELECT * FROM accounts_timetravel;

CREATE TABLE foo(id int);
-- increment the catalog version
ALTER TABLE foo ADD COLUMN val TEXT;

SELECT * FROM pg_yb_catalog_version;
-- === 4. PERFORM THE TIME-TRAVEL QUERY ===
--
-- Set our 'read_time_guc' variable to the HLC value
--
\set read_time_guc :snapshot_hlc

\echo '--- 3. Time-Travel Read (Querying the Past) ---'
\echo 'Setting yb_read_time to HLC (microseconds):' :read_time_guc

-- This will now be interpolated correctly and will succeed.
SET yb_read_time = :read_time_guc;

-- This query will now correctly read the historical data
SELECT * FROM accounts_timetravel;
SELECT * FROM pg_yb_catalog_version;

-- === 5. CLEANUP ===
RESET yb_read_time;
\echo '--- 4. Back to the Present ---'
SELECT * FROM accounts_timetravel;

DROP TABLE accounts_timetravel;
```

(4) Look at the postgres log for the following samples:

```
2025-11-07 18:31:06.223 UTC [3321231] LOG:  Preloading relcache for database 13524, session user id: 10, yb_read_time: 0
```

```
2025-11-07 18:31:06.303 UTC [3321231] LOG:  Building relcache entry for pg_index (oid 2610) took 785 us
```

```
2025-11-07 18:31:09.265 UTC [3321221] LOG:  Rebuild relcache entry for accounts_timetravel (oid 16384)
```

```
2025-11-07 18:31:09.525 UTC [3321221] LOG:  Delete relcache entry for accounts_timetravel (oid 16384)
```

```
2025-11-07 18:31:14.035 UTC [3321221] DEBUG:  Setting yb_read_time to 1762540271568993
```

```
2025-11-07 18:31:14.037 UTC [3321221] LOG:  Preloading relcache for database 13524, session user id: 13523, yb_read_time: 1762540271568993
```

```
2025-11-07 18:31:14.183 UTC [3321221] DEBUG:  Setting yb_read_time to 0
```

Reviewers: kfranz, #db-approvers

Reviewed By: kfranz, #db-approvers

Subscribers: jason, yql

Differential Revision: https://phorge.dev.yugabyte.com/D48114

Author: myang2021

src/postgres/src/backend/utils/cache/relcache.c

@@ -117,6 +117,7 @@
 #include "utils/relcache.h"
 #include "utils/yb_inheritscache.h"
 #include "utils/yb_tuplecache.h"
+#include "yb/yql/pggate/util/ybc_guc.h"
 #include "yb/yql/pggate/ybc_gflags.h"
 #include <inttypes.h>
 
@@ -1554,6 +1555,9 @@ YBLoadRelations(YbUpdateRelationCacheState *state)
 		/* make sure relation is marked as having no open file yet */
 		relation->rd_smgr = NULL;
 
+		if (yb_debug_log_catcache_events)
+			elog(LOG, "Insert relcache entry %p for %s (oid %u)", relation,
+				 RelationGetRelationName(relation), relid);
 		RelationCacheInsert(relation, true);
 
 		/* It's fully valid */
@@ -2963,9 +2967,12 @@ static YbcStatus
 YbPreloadRelCacheImpl(YbRunWithPrefetcherContext *ctx)
 {
 	YbNumRelCachePreloads++;
-	if (Log_connections || *(YBCGetGFlags()->ysql_enable_relcache_init_optimization))
-		elog(LOG, "Preloading relcache for database %u, session user id: %u",
-			 MyDatabaseId, GetSessionUserId());
+	int log_level =
+		(Log_connections ||
+		 yb_debug_log_catcache_events ||
+		 *(YBCGetGFlags()->ysql_enable_relcache_init_optimization)) ? LOG : DEBUG1;
+	elog(log_level, "Preloading relcache for database %u, session user id: %u, yb_read_time: %" PRIu64,
+		 MyDatabaseId, GetSessionUserId(), yb_read_time);
 
 	/*
 	 * During relcache loading postgres reads the data from multiple sys tables.
@@ -3419,7 +3426,7 @@ RelationBuildDesc(Oid targetRelId, bool insertIt)
 
 		INSTR_TIME_SET_CURRENT(duration);
 		INSTR_TIME_SUBTRACT(duration, start);
-		elog(LOG, "Rebuilding relcache entry for %s (oid %d) took %ld us",
+		elog(LOG, "Building relcache entry %p for %s (oid %u) took %ld us", relation,
 			 RelationGetRelationName(relation), RelationGetRelid(relation),
 			 INSTR_TIME_GET_MICROSEC(duration));
 	}
@@ -4705,6 +4712,10 @@ RelationClearRelation(Relation relation, bool rebuild)
 	 */
 	if (!rebuild)
 	{
+		if (yb_debug_log_catcache_events)
+			elog(LOG, "Delete relcache entry %p for %s (oid %u)", relation,
+				 RelationGetRelationName(relation), RelationGetRelid(relation));
+
 		/* Remove it from the hash table */
 		RelationCacheDelete(relation);
 
@@ -4808,6 +4819,10 @@ RelationClearRelation(Relation relation, bool rebuild)
 			elog(ERROR, "relation %u deleted while still in use", save_relid);
 		}
 
+		if (yb_debug_log_catcache_events)
+			elog(LOG, "Rebuild relcache entry %p for %s (oid %u)", relation,
+				 RelationGetRelationName(relation), save_relid);
+
 		keep_tupdesc = equalTupleDescs(relation->rd_att, newrel->rd_att);
 		keep_rules = equalRuleLocks(relation->rd_rules, newrel->rd_rules);
 		keep_policies = equalRSDesc(relation->rd_rsdesc, newrel->rd_rsdesc);
@@ -9072,7 +9087,13 @@ load_relcache_init_file(bool shared, bool yb_retry)
 	for (relno = 0; relno < num_rels; relno++)
 	{
 		if (YBIsDBCatalogVersionMode())
+		{
+			Relation relation = rels[relno];
+			if (yb_debug_log_catcache_events)
+				elog(LOG, "Reinsert relcache entry %p for %s (oid %u)", relation,
+					 RelationGetRelationName(relation), RelationGetRelid(relation));
 			YbRelationCacheReinsert(rels[relno], shared, yb_retry);
+		}
 		else
 			RelationCacheInsert(rels[relno], false);
 	}

src/postgres/src/backend/utils/misc/pg_yb_utils.c

@@ -6811,6 +6811,7 @@ assign_yb_read_time(const char *newval, void *extra)
 	unsigned long long value_ull;
 	bool		is_ht_unit;
 
+	elog(DEBUG1, "Setting yb_read_time to %s", newval);
 	parse_yb_read_time(newval, &value_ull, &is_ht_unit);
 	/*
 	 * Don't refresh the sys caches in case the read time value didn't change.
@@ -7797,15 +7798,13 @@ YBCUpdateYbReadTimeAndInvalidateRelcache(uint64_t read_time_ht)
 	char		read_time[50];
 
 	sprintf(read_time, "%llu ht", (unsigned long long) read_time_ht);
-	elog(DEBUG1, "Setting yb_read_time to %s ", read_time);
 	assign_yb_read_time(read_time, NULL);
 	YbRelationCacheInvalidate();
 }
 
 void
 YBCResetYbReadTimeAndInvalidateRelcache()
 {
-	elog(DEBUG1, "Setting yb_read_time to 0");
 	assign_yb_read_time("0", NULL);
 	YbRelationCacheInvalidate();
 }