Log extension state changes

To debug issues with extension state not being correct we log extension
state changes on `DEBUG1` level.

See timescale#1682

.unreleased/fix_6512

@@ -0,0 +1 @@
+Fixes: #6512 Log extension state changes

src/extension.c

@@ -66,6 +66,13 @@ static enum ExtensionState extstate = EXTENSION_STATE_UNKNOWN;
  */
 static Oid ts_extension_oid = InvalidOid;
 
+static const char *extstate_str[] = {
+	[EXTENSION_STATE_UNKNOWN] = "unknown",
+	[EXTENSION_STATE_TRANSITIONING] = "transitioning",
+	[EXTENSION_STATE_CREATED] = "created",
+	[EXTENSION_STATE_NOT_INSTALLED] = "not installed",
+};
+
 static bool
 extension_loader_present()
 {
@@ -150,6 +157,10 @@ extension_set_state(enum ExtensionState newstate)
 			ts_catalog_reset();
 			break;
 	}
+	elog(DEBUG1,
+		 "extension state changed: %s to %s",
+		 extstate_str[extstate],
+		 extstate_str[newstate]);
 	extstate = newstate;
 	return true;
 }
@@ -261,6 +272,10 @@ ts_experimental_schema_name(void)
 void
 ts_extension_invalidate(void)
 {
+	elog(DEBUG1,
+		 "extension state invalidated: %s to %s",
+		 extstate_str[extstate],
+		 extstate_str[EXTENSION_STATE_UNKNOWN]);
 	extstate = EXTENSION_STATE_UNKNOWN;
 	extension_proxy_oid = InvalidOid;
 }
@@ -335,13 +350,6 @@ ts_extension_is_proxy_table_relid(Oid relid)
 }
 
 #ifdef TS_DEBUG
-static const char *extstate_str[] = {
-	[EXTENSION_STATE_UNKNOWN] = "unknown",
-	[EXTENSION_STATE_TRANSITIONING] = "transitioning",
-	[EXTENSION_STATE_CREATED] = "created",
-	[EXTENSION_STATE_NOT_INSTALLED] = "not installed",
-};
-
 TS_FUNCTION_INFO_V1(ts_extension_get_state);
 
 Datum

tsl/test/expected/bgw_scheduler_control.out

@@ -92,14 +92,15 @@ SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(25, 0);
 SELECT * FROM cleaned_bgw_log;
  msg_no | application_name |                                   msg                                   
 --------+------------------+-------------------------------------------------------------------------
-      0 | DB Scheduler     | database scheduler for database (RANDOM) starting
-      1 | DB Scheduler     | launching job 1000 "test_job_1b"
-      2 | DB Scheduler     | [TESTING] Registered new background worker
-      3 | DB Scheduler     | [TESTING] Wait until (RANDOM), started at (RANDOM)
+      0 | DB Scheduler     | extension state changed: unknown to created
+      1 | DB Scheduler     | database scheduler for database (RANDOM) starting
+      2 | DB Scheduler     | launching job 1000 "test_job_1b"
+      3 | DB Scheduler     | [TESTING] Registered new background worker
+      4 | DB Scheduler     | [TESTING] Wait until (RANDOM), started at (RANDOM)
       0 | test_job_1b      | Execute job 1
       1 | test_job_1b      | job 1000 (test_job_1b) exiting with success: execution time (RANDOM) ms
-      4 | DB Scheduler     | database scheduler for database (RANDOM) exiting
-(7 rows)
+      5 | DB Scheduler     | database scheduler for database (RANDOM) exiting
+(8 rows)
 
 ALTER DATABASE :TEST_DBNAME RESET timescaledb.bgw_log_level;
 SELECT pg_reload_conf();