agora inbox for [email protected]  
help / color / mirror / Atom feed
[PATCH v60 08/17] pgstat: Introduce pgstat_relation_should_count().
9+ messages / 5 participants
[nested] [flat]

* [PATCH v60 08/17] pgstat: Introduce pgstat_relation_should_count().
@ 2021-04-04 04:30  Andres Freund <[email protected]>
  0 siblings, 0 replies; 9+ messages in thread

From: Andres Freund @ 2021-04-04 04:30 UTC (permalink / raw)

---
 src/include/pgstat.h                 | 22 +++++++----
 src/include/utils/rel.h              |  1 +
 src/backend/access/common/relation.c |  4 +-
 src/backend/catalog/index.c          |  2 +-
 src/backend/postmaster/pgstat.c      | 59 +++++++++++++++++-----------
 5 files changed, 53 insertions(+), 35 deletions(-)

diff --git a/src/include/pgstat.h b/src/include/pgstat.h
index 291e5ab1698..a34bb328e60 100644
--- a/src/include/pgstat.h
+++ b/src/include/pgstat.h
@@ -1030,43 +1030,49 @@ extern void pgstat_initialize(void);
 extern PgStat_TableStatus *find_tabstat_entry(Oid rel_id);
 extern PgStat_BackendFunctionEntry *find_funcstat_entry(Oid func_id);
 
-extern void pgstat_initstats(Relation rel);
+extern void pgstat_relation_init(Relation rel);
+extern void pgstat_relation_assoc(Relation rel);
+
+#define pgstat_relation_should_count(rel)                           \
+	(likely((rel)->pgstat_info != NULL) ? true :                    \
+	 ((rel)->pgstat_enabled ? pgstat_relation_assoc(rel), true : false))
+
 
 /* nontransactional event counts are simple enough to inline */
 
 #define pgstat_count_heap_scan(rel)									\
 	do {															\
-		if ((rel)->pgstat_info != NULL)								\
+		if (pgstat_relation_should_count(rel))						\
 			(rel)->pgstat_info->t_counts.t_numscans++;				\
 	} while (0)
 #define pgstat_count_heap_getnext(rel)								\
 	do {															\
-		if ((rel)->pgstat_info != NULL)								\
+		if (pgstat_relation_should_count(rel))						\
 			(rel)->pgstat_info->t_counts.t_tuples_returned++;		\
 	} while (0)
 #define pgstat_count_heap_fetch(rel)								\
 	do {															\
-		if ((rel)->pgstat_info != NULL)								\
+		if (pgstat_relation_should_count(rel))						\
 			(rel)->pgstat_info->t_counts.t_tuples_fetched++;		\
 	} while (0)
 #define pgstat_count_index_scan(rel)								\
 	do {															\
-		if ((rel)->pgstat_info != NULL)								\
+		if (pgstat_relation_should_count(rel))						\
 			(rel)->pgstat_info->t_counts.t_numscans++;				\
 	} while (0)
 #define pgstat_count_index_tuples(rel, n)							\
 	do {															\
-		if ((rel)->pgstat_info != NULL)								\
+		if (pgstat_relation_should_count(rel))						\
 			(rel)->pgstat_info->t_counts.t_tuples_returned += (n);	\
 	} while (0)
 #define pgstat_count_buffer_read(rel)								\
 	do {															\
-		if ((rel)->pgstat_info != NULL)								\
+		if (pgstat_relation_should_count(rel))						\
 			(rel)->pgstat_info->t_counts.t_blocks_fetched++;		\
 	} while (0)
 #define pgstat_count_buffer_hit(rel)								\
 	do {															\
-		if ((rel)->pgstat_info != NULL)								\
+		if (pgstat_relation_should_count(rel))						\
 			(rel)->pgstat_info->t_counts.t_blocks_hit++;			\
 	} while (0)
 #define pgstat_count_buffer_read_time(n)							\
diff --git a/src/include/utils/rel.h b/src/include/utils/rel.h
index 9a3a03e5207..e032612d39f 100644
--- a/src/include/utils/rel.h
+++ b/src/include/utils/rel.h
@@ -234,6 +234,7 @@ typedef struct RelationData
 	Oid			rd_toastoid;	/* Real TOAST table's OID, or InvalidOid */
 
 	/* use "struct" here to avoid needing to include pgstat.h: */
+	bool		pgstat_enabled;
 	struct PgStat_TableStatus *pgstat_info; /* statistics collection area */
 } RelationData;
 
diff --git a/src/backend/access/common/relation.c b/src/backend/access/common/relation.c
index 632d13c1eaf..3721bad1daf 100644
--- a/src/backend/access/common/relation.c
+++ b/src/backend/access/common/relation.c
@@ -73,7 +73,7 @@ relation_open(Oid relationId, LOCKMODE lockmode)
 	if (RelationUsesLocalBuffers(r))
 		MyXactFlags |= XACT_FLAGS_ACCESSEDTEMPNAMESPACE;
 
-	pgstat_initstats(r);
+	pgstat_relation_init(r);
 
 	return r;
 }
@@ -123,7 +123,7 @@ try_relation_open(Oid relationId, LOCKMODE lockmode)
 	if (RelationUsesLocalBuffers(r))
 		MyXactFlags |= XACT_FLAGS_ACCESSEDTEMPNAMESPACE;
 
-	pgstat_initstats(r);
+	pgstat_relation_init(r);
 
 	return r;
 }
diff --git a/src/backend/catalog/index.c b/src/backend/catalog/index.c
index a628b3281ce..7c5c2093328 100644
--- a/src/backend/catalog/index.c
+++ b/src/backend/catalog/index.c
@@ -1877,7 +1877,7 @@ index_concurrently_swap(Oid newIndexId, Oid oldIndexId, const char *oldName)
 		tabentry = pgstat_fetch_stat_tabentry(oldIndexId);
 		if (tabentry)
 		{
-			if (newClassRel->pgstat_info)
+			if (pgstat_relation_should_count(newClassRel))
 			{
 				newClassRel->pgstat_info->t_counts.t_numscans = tabentry->numscans;
 				newClassRel->pgstat_info->t_counts.t_tuples_returned = tabentry->tuples_returned;
diff --git a/src/backend/postmaster/pgstat.c b/src/backend/postmaster/pgstat.c
index bf93d0cd55e..6c4ba9932de 100644
--- a/src/backend/postmaster/pgstat.c
+++ b/src/backend/postmaster/pgstat.c
@@ -183,7 +183,7 @@ static bool pgStatRunningInCollector = false;
  * for the life of the backend.  Also, we zero out the t_id fields of the
  * contained PgStat_TableStatus structs whenever they are not actively in use.
  * This allows relcache pgstat_info pointers to be treated as long-lived data,
- * avoiding repeated searches in pgstat_initstats() when a relation is
+ * avoiding repeated searches in pgstat_relation_assoc() when a relation is
  * repeatedly opened during a transaction.
  */
 #define TABSTAT_QUANTUM		100 /* we alloc this many at a time */
@@ -1617,7 +1617,7 @@ pgstat_report_analyze(Relation rel,
 	 * collector ends up with the right numbers if we abort instead of
 	 * committing.)
 	 */
-	if (rel->pgstat_info != NULL)
+	if (pgstat_relation_should_count(rel))
 	{
 		PgStat_TableXactStatus *trans;
 
@@ -1943,7 +1943,7 @@ pgstat_end_function_usage(PgStat_FunctionCallUsage *fcu, bool finalize)
 
 
 /* ----------
- * pgstat_initstats() -
+ * pgstat_relation_init() -
  *
  *	Initialize a relcache entry to count access statistics.
  *	Called whenever a relation is opened.
@@ -1955,7 +1955,7 @@ pgstat_end_function_usage(PgStat_FunctionCallUsage *fcu, bool finalize)
  * ----------
  */
 void
-pgstat_initstats(Relation rel)
+pgstat_relation_init(Relation rel)
 {
 	Oid			rel_id = rel->rd_id;
 	char		relkind = rel->rd_rel->relkind;
@@ -1963,6 +1963,7 @@ pgstat_initstats(Relation rel)
 	/* We only count stats for things that have storage */
 	if (!RELKIND_HAS_STORAGE(relkind))
 	{
+		rel->pgstat_enabled = false;
 		rel->pgstat_info = NULL;
 		return;
 	}
@@ -1970,6 +1971,7 @@ pgstat_initstats(Relation rel)
 	if (pgStatSock == PGINVALID_SOCKET || !pgstat_track_counts)
 	{
 		/* We're not counting at all */
+		rel->pgstat_enabled = false;
 		rel->pgstat_info = NULL;
 		return;
 	}
@@ -1978,11 +1980,22 @@ pgstat_initstats(Relation rel)
 	 * If we already set up this relation in the current transaction, nothing
 	 * to do.
 	 */
-	if (rel->pgstat_info != NULL &&
+	if (rel->pgstat_info &&
 		rel->pgstat_info->t_id == rel_id)
 		return;
 
-	/* Else find or make the PgStat_TableStatus entry, and update link */
+	rel->pgstat_enabled = true;
+}
+
+void
+pgstat_relation_assoc(Relation rel)
+{
+	Oid			rel_id = rel->rd_id;
+
+	Assert(rel->pgstat_enabled);
+	Assert(rel->pgstat_info == NULL);
+
+	/* find or make the PgStat_TableStatus entry, and update link */
 	rel->pgstat_info = get_tabstat_entry(rel_id, rel->rd_rel->relisshared);
 }
 
@@ -2149,13 +2162,12 @@ add_tabstat_xact_level(PgStat_TableStatus *pgstat_info, int nest_level)
 void
 pgstat_count_heap_insert(Relation rel, PgStat_Counter n)
 {
-	PgStat_TableStatus *pgstat_info = rel->pgstat_info;
-
-	if (pgstat_info != NULL)
+	if (pgstat_relation_should_count(rel))
 	{
-		/* We have to log the effect at the proper transactional level */
+		PgStat_TableStatus *pgstat_info = rel->pgstat_info;
 		int			nest_level = GetCurrentTransactionNestLevel();
 
+		/* We have to log the effect at the proper transactional level */
 		if (pgstat_info->trans == NULL ||
 			pgstat_info->trans->nest_level != nest_level)
 			add_tabstat_xact_level(pgstat_info, nest_level);
@@ -2170,13 +2182,12 @@ pgstat_count_heap_insert(Relation rel, PgStat_Counter n)
 void
 pgstat_count_heap_update(Relation rel, bool hot)
 {
-	PgStat_TableStatus *pgstat_info = rel->pgstat_info;
-
-	if (pgstat_info != NULL)
+	if (pgstat_relation_should_count(rel))
 	{
-		/* We have to log the effect at the proper transactional level */
+		PgStat_TableStatus *pgstat_info = rel->pgstat_info;
 		int			nest_level = GetCurrentTransactionNestLevel();
 
+		/* We have to log the effect at the proper transactional level */
 		if (pgstat_info->trans == NULL ||
 			pgstat_info->trans->nest_level != nest_level)
 			add_tabstat_xact_level(pgstat_info, nest_level);
@@ -2195,13 +2206,12 @@ pgstat_count_heap_update(Relation rel, bool hot)
 void
 pgstat_count_heap_delete(Relation rel)
 {
-	PgStat_TableStatus *pgstat_info = rel->pgstat_info;
-
-	if (pgstat_info != NULL)
+	if (pgstat_relation_should_count(rel))
 	{
-		/* We have to log the effect at the proper transactional level */
+		PgStat_TableStatus *pgstat_info = rel->pgstat_info;
 		int			nest_level = GetCurrentTransactionNestLevel();
 
+		/* We have to log the effect at the proper transactional level */
 		if (pgstat_info->trans == NULL ||
 			pgstat_info->trans->nest_level != nest_level)
 			add_tabstat_xact_level(pgstat_info, nest_level);
@@ -2253,13 +2263,12 @@ pgstat_truncdrop_restore_counters(PgStat_TableXactStatus *trans)
 void
 pgstat_count_truncate(Relation rel)
 {
-	PgStat_TableStatus *pgstat_info = rel->pgstat_info;
-
-	if (pgstat_info != NULL)
+	if (pgstat_relation_should_count(rel))
 	{
-		/* We have to log the effect at the proper transactional level */
+		PgStat_TableStatus *pgstat_info = rel->pgstat_info;
 		int			nest_level = GetCurrentTransactionNestLevel();
 
+		/* We have to log the effect at the proper transactional level */
 		if (pgstat_info->trans == NULL ||
 			pgstat_info->trans->nest_level != nest_level)
 			add_tabstat_xact_level(pgstat_info, nest_level);
@@ -2282,10 +2291,12 @@ pgstat_count_truncate(Relation rel)
 void
 pgstat_update_heap_dead_tuples(Relation rel, int delta)
 {
-	PgStat_TableStatus *pgstat_info = rel->pgstat_info;
+	if (pgstat_relation_should_count(rel))
+	{
+		PgStat_TableStatus *pgstat_info = rel->pgstat_info;
 
-	if (pgstat_info != NULL)
 		pgstat_info->t_counts.t_delta_dead_tuples -= delta;
+	}
 }
 
 /*
-- 
2.31.0.121.g9198c13e34


--zefjd6adjk3g4ecc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v60-0009-pgstat-xact-level-cleanups-consolidation.patch"



^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* [PATCH v65 02/11] pgstat: Introduce pgstat_relation_should_count().
@ 2022-03-03 02:02  Andres Freund <[email protected]>
  0 siblings, 0 replies; 9+ messages in thread

From: Andres Freund @ 2022-03-03 02:02 UTC (permalink / raw)

---
 src/include/pgstat.h                 | 27 +++++++++----
 src/include/utils/rel.h              |  1 +
 src/backend/access/common/relation.c |  4 +-
 src/backend/catalog/index.c          |  2 +-
 src/backend/postmaster/pgstat.c      | 59 +++++++++++++++++-----------
 5 files changed, 58 insertions(+), 35 deletions(-)

diff --git a/src/include/pgstat.h b/src/include/pgstat.h
index be2f7e2bcc7..f808955125b 100644
--- a/src/include/pgstat.h
+++ b/src/include/pgstat.h
@@ -1102,43 +1102,54 @@ extern void pgstat_initialize(void);
 extern PgStat_TableStatus *find_tabstat_entry(Oid rel_id);
 extern PgStat_BackendFunctionEntry *find_funcstat_entry(Oid func_id);
 
-extern void pgstat_initstats(Relation rel);
+extern void pgstat_relation_init(Relation rel);
+extern void pgstat_relation_assoc(Relation rel);
+
+/*
+ * AFIXME: pgstat_enabled should instead be tri-valued (disabled,
+ * needs-initialization, initialized). Then we don't need to check two
+ * separate variables.
+ */
+#define pgstat_relation_should_count(rel)                           \
+	(likely((rel)->pgstat_info != NULL) ? true :                    \
+	 ((rel)->pgstat_enabled ? pgstat_relation_assoc(rel), true : false))
+
 
 /* nontransactional event counts are simple enough to inline */
 
 #define pgstat_count_heap_scan(rel)									\
 	do {															\
-		if ((rel)->pgstat_info != NULL)								\
+		if (pgstat_relation_should_count(rel))						\
 			(rel)->pgstat_info->t_counts.t_numscans++;				\
 	} while (0)
 #define pgstat_count_heap_getnext(rel)								\
 	do {															\
-		if ((rel)->pgstat_info != NULL)								\
+		if (pgstat_relation_should_count(rel))						\
 			(rel)->pgstat_info->t_counts.t_tuples_returned++;		\
 	} while (0)
 #define pgstat_count_heap_fetch(rel)								\
 	do {															\
-		if ((rel)->pgstat_info != NULL)								\
+		if (pgstat_relation_should_count(rel))						\
 			(rel)->pgstat_info->t_counts.t_tuples_fetched++;		\
 	} while (0)
 #define pgstat_count_index_scan(rel)								\
 	do {															\
-		if ((rel)->pgstat_info != NULL)								\
+		if (pgstat_relation_should_count(rel))						\
 			(rel)->pgstat_info->t_counts.t_numscans++;				\
 	} while (0)
 #define pgstat_count_index_tuples(rel, n)							\
 	do {															\
-		if ((rel)->pgstat_info != NULL)								\
+		if (pgstat_relation_should_count(rel))						\
 			(rel)->pgstat_info->t_counts.t_tuples_returned += (n);	\
 	} while (0)
 #define pgstat_count_buffer_read(rel)								\
 	do {															\
-		if ((rel)->pgstat_info != NULL)								\
+		if (pgstat_relation_should_count(rel))						\
 			(rel)->pgstat_info->t_counts.t_blocks_fetched++;		\
 	} while (0)
 #define pgstat_count_buffer_hit(rel)								\
 	do {															\
-		if ((rel)->pgstat_info != NULL)								\
+		if (pgstat_relation_should_count(rel))						\
 			(rel)->pgstat_info->t_counts.t_blocks_hit++;			\
 	} while (0)
 #define pgstat_count_buffer_read_time(n)							\
diff --git a/src/include/utils/rel.h b/src/include/utils/rel.h
index 3b4ab65ae20..485d38ecee3 100644
--- a/src/include/utils/rel.h
+++ b/src/include/utils/rel.h
@@ -247,6 +247,7 @@ typedef struct RelationData
 	Oid			rd_toastoid;	/* Real TOAST table's OID, or InvalidOid */
 
 	/* use "struct" here to avoid needing to include pgstat.h: */
+	bool		pgstat_enabled;
 	struct PgStat_TableStatus *pgstat_info; /* statistics collection area */
 } RelationData;
 
diff --git a/src/backend/access/common/relation.c b/src/backend/access/common/relation.c
index 1c02bf03a34..003663ab811 100644
--- a/src/backend/access/common/relation.c
+++ b/src/backend/access/common/relation.c
@@ -73,7 +73,7 @@ relation_open(Oid relationId, LOCKMODE lockmode)
 	if (RelationUsesLocalBuffers(r))
 		MyXactFlags |= XACT_FLAGS_ACCESSEDTEMPNAMESPACE;
 
-	pgstat_initstats(r);
+	pgstat_relation_init(r);
 
 	return r;
 }
@@ -123,7 +123,7 @@ try_relation_open(Oid relationId, LOCKMODE lockmode)
 	if (RelationUsesLocalBuffers(r))
 		MyXactFlags |= XACT_FLAGS_ACCESSEDTEMPNAMESPACE;
 
-	pgstat_initstats(r);
+	pgstat_relation_init(r);
 
 	return r;
 }
diff --git a/src/backend/catalog/index.c b/src/backend/catalog/index.c
index 5e3fc2b35dc..a9e69b8122b 100644
--- a/src/backend/catalog/index.c
+++ b/src/backend/catalog/index.c
@@ -1743,7 +1743,7 @@ index_concurrently_swap(Oid newIndexId, Oid oldIndexId, const char *oldName)
 		tabentry = pgstat_fetch_stat_tabentry(oldIndexId);
 		if (tabentry)
 		{
-			if (newClassRel->pgstat_info)
+			if (pgstat_relation_should_count(newClassRel))
 			{
 				newClassRel->pgstat_info->t_counts.t_numscans = tabentry->numscans;
 				newClassRel->pgstat_info->t_counts.t_tuples_returned = tabentry->tuples_returned;
diff --git a/src/backend/postmaster/pgstat.c b/src/backend/postmaster/pgstat.c
index 53ddd930e6e..de45a10334b 100644
--- a/src/backend/postmaster/pgstat.c
+++ b/src/backend/postmaster/pgstat.c
@@ -188,7 +188,7 @@ static bool pgStatRunningInCollector = false;
  * for the life of the backend.  Also, we zero out the t_id fields of the
  * contained PgStat_TableStatus structs whenever they are not actively in use.
  * This allows relcache pgstat_info pointers to be treated as long-lived data,
- * avoiding repeated searches in pgstat_initstats() when a relation is
+ * avoiding repeated searches in pgstat_relation_assoc() when a relation is
  * repeatedly opened during a transaction.
  */
 #define TABSTAT_QUANTUM		100 /* we alloc this many at a time */
@@ -1683,7 +1683,7 @@ pgstat_report_analyze(Relation rel,
 	 *
 	 * Waste no time on partitioned tables, though.
 	 */
-	if (rel->pgstat_info != NULL &&
+	if (pgstat_relation_should_count(rel) &&
 		rel->rd_rel->relkind != RELKIND_PARTITIONED_TABLE)
 	{
 		PgStat_TableXactStatus *trans;
@@ -2121,7 +2121,7 @@ pgstat_end_function_usage(PgStat_FunctionCallUsage *fcu, bool finalize)
 
 
 /* ----------
- * pgstat_initstats() -
+ * pgstat_relation_init() -
  *
  *	Initialize a relcache entry to count access statistics.
  *	Called whenever a relation is opened.
@@ -2133,7 +2133,7 @@ pgstat_end_function_usage(PgStat_FunctionCallUsage *fcu, bool finalize)
  * ----------
  */
 void
-pgstat_initstats(Relation rel)
+pgstat_relation_init(Relation rel)
 {
 	Oid			rel_id = rel->rd_id;
 	char		relkind = rel->rd_rel->relkind;
@@ -2143,6 +2143,7 @@ pgstat_initstats(Relation rel)
 	 */
 	if (!RELKIND_HAS_STORAGE(relkind) && relkind != RELKIND_PARTITIONED_TABLE)
 	{
+		rel->pgstat_enabled = false;
 		rel->pgstat_info = NULL;
 		return;
 	}
@@ -2150,6 +2151,7 @@ pgstat_initstats(Relation rel)
 	if (pgStatSock == PGINVALID_SOCKET || !pgstat_track_counts)
 	{
 		/* We're not counting at all */
+		rel->pgstat_enabled = false;
 		rel->pgstat_info = NULL;
 		return;
 	}
@@ -2158,11 +2160,22 @@ pgstat_initstats(Relation rel)
 	 * If we already set up this relation in the current transaction, nothing
 	 * to do.
 	 */
-	if (rel->pgstat_info != NULL &&
+	if (rel->pgstat_info &&
 		rel->pgstat_info->t_id == rel_id)
 		return;
 
-	/* Else find or make the PgStat_TableStatus entry, and update link */
+	rel->pgstat_enabled = true;
+}
+
+void
+pgstat_relation_assoc(Relation rel)
+{
+	Oid			rel_id = rel->rd_id;
+
+	Assert(rel->pgstat_enabled);
+	Assert(rel->pgstat_info == NULL);
+
+	/* find or make the PgStat_TableStatus entry, and update link */
 	rel->pgstat_info = get_tabstat_entry(rel_id, rel->rd_rel->relisshared);
 }
 
@@ -2331,13 +2344,12 @@ add_tabstat_xact_level(PgStat_TableStatus *pgstat_info, int nest_level)
 void
 pgstat_count_heap_insert(Relation rel, PgStat_Counter n)
 {
-	PgStat_TableStatus *pgstat_info = rel->pgstat_info;
-
-	if (pgstat_info != NULL)
+	if (pgstat_relation_should_count(rel))
 	{
-		/* We have to log the effect at the proper transactional level */
+		PgStat_TableStatus *pgstat_info = rel->pgstat_info;
 		int			nest_level = GetCurrentTransactionNestLevel();
 
+		/* We have to log the effect at the proper transactional level */
 		if (pgstat_info->trans == NULL ||
 			pgstat_info->trans->nest_level != nest_level)
 			add_tabstat_xact_level(pgstat_info, nest_level);
@@ -2352,13 +2364,12 @@ pgstat_count_heap_insert(Relation rel, PgStat_Counter n)
 void
 pgstat_count_heap_update(Relation rel, bool hot)
 {
-	PgStat_TableStatus *pgstat_info = rel->pgstat_info;
-
-	if (pgstat_info != NULL)
+	if (pgstat_relation_should_count(rel))
 	{
-		/* We have to log the effect at the proper transactional level */
+		PgStat_TableStatus *pgstat_info = rel->pgstat_info;
 		int			nest_level = GetCurrentTransactionNestLevel();
 
+		/* We have to log the effect at the proper transactional level */
 		if (pgstat_info->trans == NULL ||
 			pgstat_info->trans->nest_level != nest_level)
 			add_tabstat_xact_level(pgstat_info, nest_level);
@@ -2377,13 +2388,12 @@ pgstat_count_heap_update(Relation rel, bool hot)
 void
 pgstat_count_heap_delete(Relation rel)
 {
-	PgStat_TableStatus *pgstat_info = rel->pgstat_info;
-
-	if (pgstat_info != NULL)
+	if (pgstat_relation_should_count(rel))
 	{
-		/* We have to log the effect at the proper transactional level */
+		PgStat_TableStatus *pgstat_info = rel->pgstat_info;
 		int			nest_level = GetCurrentTransactionNestLevel();
 
+		/* We have to log the effect at the proper transactional level */
 		if (pgstat_info->trans == NULL ||
 			pgstat_info->trans->nest_level != nest_level)
 			add_tabstat_xact_level(pgstat_info, nest_level);
@@ -2435,13 +2445,12 @@ pgstat_truncdrop_restore_counters(PgStat_TableXactStatus *trans)
 void
 pgstat_count_truncate(Relation rel)
 {
-	PgStat_TableStatus *pgstat_info = rel->pgstat_info;
-
-	if (pgstat_info != NULL)
+	if (pgstat_relation_should_count(rel))
 	{
-		/* We have to log the effect at the proper transactional level */
+		PgStat_TableStatus *pgstat_info = rel->pgstat_info;
 		int			nest_level = GetCurrentTransactionNestLevel();
 
+		/* We have to log the effect at the proper transactional level */
 		if (pgstat_info->trans == NULL ||
 			pgstat_info->trans->nest_level != nest_level)
 			add_tabstat_xact_level(pgstat_info, nest_level);
@@ -2464,10 +2473,12 @@ pgstat_count_truncate(Relation rel)
 void
 pgstat_update_heap_dead_tuples(Relation rel, int delta)
 {
-	PgStat_TableStatus *pgstat_info = rel->pgstat_info;
+	if (pgstat_relation_should_count(rel))
+	{
+		PgStat_TableStatus *pgstat_info = rel->pgstat_info;
 
-	if (pgstat_info != NULL)
 		pgstat_info->t_counts.t_delta_dead_tuples -= delta;
+	}
 }
 
 /*
-- 
2.35.1.354.g715d08a9e5


--6rwz5pdckqwec52m
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v65-0003-pgstat-xact-level-cleanups-consolidation.patch"



^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* [PATCH] pgbench log file headers
@ 2023-11-13 17:55  Adam Hendel <[email protected]>
  0 siblings, 2 replies; 9+ messages in thread

From: Adam Hendel @ 2023-11-13 17:55 UTC (permalink / raw)
  To: [email protected]

Hello Hackers!

Currently, pgbench will log individual transactions to a logfile when the
`--log` parameter flag is provided. The logfile, however, does not include
column header. It has become a fairly standard expectation of users to have
column headers present in flat files. Without the header in the pgbench log
files, new users must navigate to the docs and piece together the column
headers themselves. Most industry leading frameworks have tooling built in
to read column headers though, for example python/pandas read_csv().

We can improve the experience for users by adding column headers to pgbench
logfiles with an optional command line flag, `--log-header`. This will keep
the API backwards compatible by making users opt-in to the column headers.
It follows the existing pattern of having conditional flags in pgbench’s
API; the `--log` option would have both –log-prefix and –log-header if this
work is accepted.

The implementation considers the column headers only when the
`--log-header` flag is present. The values for the columns are taken
directly from the “Per-Transaction Logging” section in
https://www.postgresql.org/docs/current/pgbench.html and takes into account
the conditional columns `schedule_lag` and `retries`.


Below is an example of what that logfile will look like:


pgbench  postgres://postgres:postgres@localhost:5432/postgres --log
--log-header

client_id transaction_no time script_no time_epoch time_us

0 1 1863 0 1699555588 791102

0 2 706 0 1699555588 791812


If the interface and overall approach makes sense, I will work on adding
documentation and tests for this too.

Respectfully,

Adam Hendel


Attachments:

  [application/octet-stream] v1-0001-Adds-log-header-flag-to-pgbench-which-adds-column.patch (4.7K, ../../CABfuTggpE-A5pvif9Zv++c4Jn3iu_7ccJ23Pm+8r+CKRBUMg_Q@mail.gmail.com/3-v1-0001-Adds-log-header-flag-to-pgbench-which-adds-column.patch)
  download | inline diff:
From f4451d36624757f893d31987b42e95eb3fd6f303 Mon Sep 17 00:00:00 2001
From: Adam Hendel <[email protected]>
Date: Thu, 9 Nov 2023 13:34:19 -0600
Subject: [PATCH v1] Adds --log-header flag to pgbench which adds column
 headers to the log file

Previously, users would be required to manually look up column names in the
documentation when reading and processing pgbench log files. Adding
--log-header outputs column headers to the logfile itself, making it easy
to process programatically. It is an optional flag, so it maintains backwards
compatibility.
---
 src/bin/pgbench/pgbench.c | 45 ++++++++++++++++++++++++++++++++++++++-
 1 file changed, 44 insertions(+), 1 deletion(-)

diff --git a/src/bin/pgbench/pgbench.c b/src/bin/pgbench/pgbench.c
index e3919395ea..189312409a 100644
--- a/src/bin/pgbench/pgbench.c
+++ b/src/bin/pgbench/pgbench.c
@@ -255,6 +255,7 @@ int64		random_seed = -1;
 #define SCALE_32BIT_THRESHOLD 20000
 
 bool		use_log;			/* log transaction latencies to a file */
+bool		use_log_header;		/* include column header in the logfile */
 bool		use_quiet;			/* quiet logging onto stderr */
 int			agg_interval;		/* log aggregates instead of individual
 								 * transactions */
@@ -822,6 +823,7 @@ static void setDoubleValue(PgBenchValue *pv, double dval);
 static bool evaluateExpr(CState *st, PgBenchExpr *expr,
 						 PgBenchValue *retval);
 static ConnectionStateEnum executeMetaCommand(CState *st, pg_time_usec_t *now);
+static void doLogHeader(FILE *logfile, double throttle_delay, uint32 retries);
 static void doLog(TState *thread, CState *st,
 				  StatsData *agg, bool skipped, double latency, double lag);
 static void processXactStats(TState *thread, CState *st, pg_time_usec_t *now,
@@ -925,6 +927,7 @@ usage(void)
 		   "  --log-prefix=PREFIX      prefix for transaction time log file\n"
 		   "                           (default: \"pgbench_log\")\n"
 		   "  --max-tries=NUM          max number of tries to run transaction (default: 1)\n"
+		   "  --log-header             write column headers to logfile\n"
 		   "  --progress-timestamp     use Unix epoch timestamps for progress\n"
 		   "  --random-seed=SEED       set random seed (\"time\", \"rand\", integer)\n"
 		   "  --sampling-rate=NUM      fraction of transactions to log (e.g., 0.01 for 1%%)\n"
@@ -4500,6 +4503,37 @@ getResultString(bool skipped, EStatus estatus)
 		return "failed";
 }
 
+/*
+ * Generate the header for the --log file
+ *
+ * schedule_lag field is only present when --rate is specified
+ * retries field is only present when --max-tries != 1
+ */
+void doLogHeader(FILE *logfile, double throttle_delay, uint32 retries)
+{
+    // header fields present in all cases
+    fprintf(logfile, "client_id transaction_no time script_no time_epoch time_us");
+    
+    // Append "schedule_lag" if the schedule_lag is true
+    if (throttle_delay)
+    {
+        fprintf(logfile, " schedule_lag");
+    }
+
+
+    // Append "retries" when set
+    if (retries > 1)
+    {
+        fprintf(logfile, " retries");
+    }
+
+    fprintf(logfile, "\n");
+
+	// flush the buffer to ensure the header is written immediately
+	fflush(logfile);
+}
+
+
 /*
  * Print log entry after completing one transaction.
  *
@@ -4517,7 +4551,6 @@ doLog(TState *thread, CState *st,
 	pg_time_usec_t now = pg_time_now() + epoch_shift;
 
 	Assert(use_log);
-
 	/*
 	 * Skip the log entry if sampling is enabled and this row doesn't belong
 	 * to the random sample.
@@ -6628,6 +6661,7 @@ main(int argc, char **argv)
 		{"max-tries", required_argument, NULL, 14},
 		{"verbose-errors", no_argument, NULL, 15},
 		{"exit-on-abort", no_argument, NULL, 16},
+		{"log-header", no_argument, NULL, 17},
 		{NULL, 0, NULL, 0}
 	};
 
@@ -6965,6 +6999,9 @@ main(int argc, char **argv)
 				benchmarking_option_set = true;
 				exit_on_abort = true;
 				break;
+			case 17:
+				use_log_header = true;
+				break;
 			default:
 				/* getopt_long already emitted a complaint */
 				pg_log_error_hint("Try \"%s --help\" for more information.", progname);
@@ -7101,6 +7138,9 @@ main(int argc, char **argv)
 	if (!use_log && logfile_prefix)
 		pg_fatal("log file prefix (--log-prefix) is allowed only when logging transactions (-l)");
 
+	if (!use_log && use_log_header)
+		pg_fatal("log header (--log-header) is allowed only when logging transactions (-l)");
+
 	if (duration > 0 && agg_interval > duration)
 		pg_fatal("number of seconds for aggregation (%d) must not be higher than test duration (%d)", agg_interval, duration);
 
@@ -7380,6 +7420,9 @@ threadRun(void *arg)
 
 		if (thread->logfile == NULL)
 			pg_fatal("could not open logfile \"%s\": %m", logpath);
+		else
+			if (use_log_header)
+				doLogHeader(thread->logfile, throttle_delay, max_tries);
 	}
 
 	/* explicitly initialize the state machines */
-- 
2.39.3 (Apple Git-145)



^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: [PATCH] pgbench log file headers
@ 2023-11-13 19:12  Andrew Atkinson <[email protected]>
  parent: Adam Hendel <[email protected]>
  1 sibling, 0 replies; 9+ messages in thread

From: Andrew Atkinson @ 2023-11-13 19:12 UTC (permalink / raw)
  To: Adam Hendel <[email protected]>; +Cc: [email protected]

Hi Adam. Column headers in pgbench log files seem helpful. Besides
programs, it seems helpful for humans to understand the column data as
well. I was able to apply your patch and verify that the headers are added
to the log file:

andy@MacBook-Air-4 ~/P/postgres (master)> rm pgbench_log.*

andy@MacBook-Air-4 ~/P/postgres (master)> src/bin/pgbench/pgbench
postgres://andy:@localhost:5432/postgres --log --log-header

pgbench (17devel)

....


andy@MacBook-Air-4 ~/P/postgres (master)> cat pgbench_log.*

client_id transaction_no time script_no time_epoch time_us

0 1 8435 0 1699902315 902700

0 2 1130 0 1699902315 903973

...



The generated pgbench_log.62387 log file showed headers "client_id
transaction_no time script_no time_epoch time_us". Hope that helps with
your patch acceptance journey.


Good luck!


Andrew Atkinson

On Mon, Nov 13, 2023 at 11:55 AM Adam Hendel <[email protected]> wrote:

> Hello Hackers!
>
> Currently, pgbench will log individual transactions to a logfile when the
> `--log` parameter flag is provided. The logfile, however, does not include
> column header. It has become a fairly standard expectation of users to have
> column headers present in flat files. Without the header in the pgbench log
> files, new users must navigate to the docs and piece together the column
> headers themselves. Most industry leading frameworks have tooling built in
> to read column headers though, for example python/pandas read_csv().
>
> We can improve the experience for users by adding column headers to
> pgbench logfiles with an optional command line flag, `--log-header`. This
> will keep the API backwards compatible by making users opt-in to the column
> headers. It follows the existing pattern of having conditional flags in
> pgbench’s API; the `--log` option would have both –log-prefix and
> –log-header if this work is accepted.
>
> The implementation considers the column headers only when the
> `--log-header` flag is present. The values for the columns are taken
> directly from the “Per-Transaction Logging” section in
> https://www.postgresql.org/docs/current/pgbench.html and takes into
> account the conditional columns `schedule_lag` and `retries`.
>
>
> Below is an example of what that logfile will look like:
>
>
> pgbench  postgres://postgres:postgres@localhost:5432/postgres --log
> --log-header
>
> client_id transaction_no time script_no time_epoch time_us
>
> 0 1 1863 0 1699555588 791102
>
> 0 2 706 0 1699555588 791812
>
>
> If the interface and overall approach makes sense, I will work on adding
> documentation and tests for this too.
>
> Respectfully,
>
> Adam Hendel
>
>


^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: [PATCH] pgbench log file headers
@ 2023-11-14 00:01  Andres Freund <[email protected]>
  parent: Adam Hendel <[email protected]>
  1 sibling, 2 replies; 9+ messages in thread

From: Andres Freund @ 2023-11-14 00:01 UTC (permalink / raw)
  To: Adam Hendel <[email protected]>; +Cc: [email protected]

Hi,

On 2023-11-13 11:55:07 -0600, Adam Hendel wrote:
> Currently, pgbench will log individual transactions to a logfile when the
> `--log` parameter flag is provided. The logfile, however, does not include
> column header. It has become a fairly standard expectation of users to have
> column headers present in flat files. Without the header in the pgbench log
> files, new users must navigate to the docs and piece together the column
> headers themselves. Most industry leading frameworks have tooling built in
> to read column headers though, for example python/pandas read_csv().

The disadvantage of doing that is that a single pgbench run with --log will
generate many files when using -j, to avoid contention. The easiest way to
deal with that after the run is to cat all the log files to a larger one. If
you do that with headers present, you obviously have a few bogus rows (the
heades from the various files).

I guess you could avoid the "worst" of that by documenting that the combined
log file should be built by
  cat {$log_prefix}.${pid} {$log_prefix}.${pid}.*
and only outputting the header in the file generated by the main thread.


> We can improve the experience for users by adding column headers to pgbench
> logfiles with an optional command line flag, `--log-header`. This will keep
> the API backwards compatible by making users opt-in to the column headers.
> It follows the existing pattern of having conditional flags in pgbench’s
> API; the `--log` option would have both –log-prefix and –log-header if this
> work is accepted.

> The implementation considers the column headers only when the
> `--log-header` flag is present. The values for the columns are taken
> directly from the “Per-Transaction Logging” section in
> https://www.postgresql.org/docs/current/pgbench.html and takes into account
> the conditional columns `schedule_lag` and `retries`.
> 
> 
> Below is an example of what that logfile will look like:
> 
> 
> pgbench  postgres://postgres:postgres@localhost:5432/postgres --log
> --log-header
> 
> client_id transaction_no time script_no time_epoch time_us

Independent of your patch, but we imo ought to combine time_epoch time_us in
the log output. There's no point in forcing consumers to combine those fields,
and it makes logging more expensive...  And if we touch this, we should just
switch to outputting nanoseconds instead of microseconds.

It also is quite odd that we have "time" and "time_epoch", "time_us", where
time is the elapsed time of an individual "transaction" and time_epoch +
time_us together are a wall-clock timestamp.  Without differentiating between
those, the column headers seem not very useful, because one needs to look in
the documentation to understand the fields.


I don't think there's all that strong a need for backward compatibility in
pgbench. We could just change the columns as I suggest above and then always
emit the header in the "main" log file.

Greetings,

Andres Freund






^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: [PATCH] pgbench log file headers
@ 2023-11-15 14:16  Adam Hendel <[email protected]>
  parent: Andres Freund <[email protected]>
  1 sibling, 0 replies; 9+ messages in thread

From: Adam Hendel @ 2023-11-15 14:16 UTC (permalink / raw)
  To: Andres Freund <[email protected]>; +Cc: [email protected]

Hello


On Mon, Nov 13, 2023 at 6:01 PM Andres Freund <[email protected]> wrote:

> Hi,
>
> On 2023-11-13 11:55:07 -0600, Adam Hendel wrote:
> > Currently, pgbench will log individual transactions to a logfile when the
> > `--log` parameter flag is provided. The logfile, however, does not
> include
> > column header. It has become a fairly standard expectation of users to
> have
> > column headers present in flat files. Without the header in the pgbench
> log
> > files, new users must navigate to the docs and piece together the column
> > headers themselves. Most industry leading frameworks have tooling built
> in
> > to read column headers though, for example python/pandas read_csv().
>
> The disadvantage of doing that is that a single pgbench run with --log will
> generate many files when using -j, to avoid contention. The easiest way to
> deal with that after the run is to cat all the log files to a larger one.
> If
> you do that with headers present, you obviously have a few bogus rows (the
> heades from the various files).
>
> I guess you could avoid the "worst" of that by documenting that the
> combined
> log file should be built by
>   cat {$log_prefix}.${pid} {$log_prefix}.${pid}.*
> and only outputting the header in the file generated by the main thread.
>
>
> We can improve the experience for users by adding column headers to
> pgbench
> > logfiles with an optional command line flag, `--log-header`. This will
> keep
> > the API backwards compatible by making users opt-in to the column
> headers.
> > It follows the existing pattern of having conditional flags in pgbench’s
> > API; the `--log` option would have both –log-prefix and –log-header if
> this
> > work is accepted.
>
> > The implementation considers the column headers only when the
> > `--log-header` flag is present. The values for the columns are taken
> > directly from the “Per-Transaction Logging” section in
> > https://www.postgresql.org/docs/current/pgbench.html and takes into
> account
> > the conditional columns `schedule_lag` and `retries`.
> >
> >
> > Below is an example of what that logfile will look like:
> >
> >
> > pgbench  postgres://postgres:postgres@localhost:5432/postgres --log
> > --log-header
> >
> > client_id transaction_no time script_no time_epoch time_us
>
> Independent of your patch, but we imo ought to combine time_epoch time_us
> in
> the log output. There's no point in forcing consumers to combine those
> fields,
> and it makes logging more expensive...  And if we touch this, we should
> just
> switch to outputting nanoseconds instead of microseconds.
>
> It also is quite odd that we have "time" and "time_epoch", "time_us", where
> time is the elapsed time of an individual "transaction" and time_epoch +
> time_us together are a wall-clock timestamp.  Without differentiating
> between
> those, the column headers seem not very useful, because one needs to look
> in
> the documentation to understand the fields.


> I don't think there's all that strong a need for backward compatibility in
> pgbench. We could just change the columns as I suggest above and then
> always
> emit the header in the "main" log file.
>
>
Do you think this should be done in separate patches?

First patch: log the column headers in the "main" log file. No --log-header
flag, make it the default behavior of --log.

Next patch: collapse "time_epoch" and "time_us" in the log output and give
the "time" column a name that is more clear.

Adam


> Greetings,
>
> Andres Freund
>


^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: [PATCH] pgbench log file headers
@ 2023-11-21 04:22  Adam Hendel <[email protected]>
  parent: Andres Freund <[email protected]>
  1 sibling, 1 reply; 9+ messages in thread

From: Adam Hendel @ 2023-11-21 04:22 UTC (permalink / raw)
  To: Andres Freund <[email protected]>; +Cc: [email protected]

Hello,

On Mon, Nov 13, 2023 at 6:01 PM Andres Freund <[email protected]> wrote:

> Hi,
>
> On 2023-11-13 11:55:07 -0600, Adam Hendel wrote:
> > Currently, pgbench will log individual transactions to a logfile when the
> > `--log` parameter flag is provided. The logfile, however, does not
> include
> > column header. It has become a fairly standard expectation of users to
> have
> > column headers present in flat files. Without the header in the pgbench
> log
> > files, new users must navigate to the docs and piece together the column
> > headers themselves. Most industry leading frameworks have tooling built
> in
> > to read column headers though, for example python/pandas read_csv().
>
> The disadvantage of doing that is that a single pgbench run with --log will
> generate many files when using -j, to avoid contention. The easiest way to
> deal with that after the run is to cat all the log files to a larger one.
> If
> you do that with headers present, you obviously have a few bogus rows (the
> heades from the various files).
>
> I guess you could avoid the "worst" of that by documenting that the
> combined
> log file should be built by
>   cat {$log_prefix}.${pid} {$log_prefix}.${pid}.*
> and only outputting the header in the file generated by the main thread.
>
>
> > We can improve the experience for users by adding column headers to
> pgbench
> > logfiles with an optional command line flag, `--log-header`. This will
> keep
> > the API backwards compatible by making users opt-in to the column
> headers.
> > It follows the existing pattern of having conditional flags in pgbench’s
> > API; the `--log` option would have both –log-prefix and –log-header if
> this
> > work is accepted.
>
> > The implementation considers the column headers only when the
> > `--log-header` flag is present. The values for the columns are taken
> > directly from the “Per-Transaction Logging” section in
> > https://www.postgresql.org/docs/current/pgbench.html and takes into
> account
> > the conditional columns `schedule_lag` and `retries`.
> >
> >
> > Below is an example of what that logfile will look like:
> >
> >
> > pgbench  postgres://postgres:postgres@localhost:5432/postgres --log
> > --log-header
> >
> > client_id transaction_no time script_no time_epoch time_us
>
> Independent of your patch, but we imo ought to combine time_epoch time_us
> in
> the log output. There's no point in forcing consumers to combine those
> fields,
> and it makes logging more expensive...  And if we touch this, we should
> just
> switch to outputting nanoseconds instead of microseconds.
>
> It also is quite odd that we have "time" and "time_epoch", "time_us", where
> time is the elapsed time of an individual "transaction" and time_epoch +
> time_us together are a wall-clock timestamp.  Without differentiating
> between
> those, the column headers seem not very useful, because one needs to look
> in
> the documentation to understand the fields.
>
>
> I don't think there's all that strong a need for backward compatibility in
> pgbench. We could just change the columns as I suggest above and then
> always
> emit the header in the "main" log file.
>

I updated the patch to always log the header and only off the main thread.
As for the time headers, I will work on renaming/combining those in a
separate commit as:

time -> time_elapsed
time_epoch + time_us -> time_completion_us



> Greetings,
>
> Andres Freund
>


Attachments:

  [application/octet-stream] v2-0001-Adds-colum-headers-to-the-log-file-produced-by-pg.patch (2.6K, ../../CABfuTggAAJ8qgY4jNt9msUTk-VOBMRHGAZqOFpd3T4QiOJz+_Q@mail.gmail.com/3-v2-0001-Adds-colum-headers-to-the-log-file-produced-by-pg.patch)
  download | inline diff:
From 444665735a1a57ece9c7dc0635ad523aa58a5a09 Mon Sep 17 00:00:00 2001
From: Adam Hendel <[email protected]>
Date: Thu, 9 Nov 2023 13:34:19 -0600
Subject: [PATCH v2] Adds colum headers to the log file produced by pgbench

Previously, users would be required to manually look up column names in the
documentation when reading and processing pgbench log files. Adding column
headers makes it it easy to process programatically.
---
 src/bin/pgbench/pgbench.c | 35 ++++++++++++++++++++++++++++++++++-
 1 file changed, 34 insertions(+), 1 deletion(-)

diff --git a/src/bin/pgbench/pgbench.c b/src/bin/pgbench/pgbench.c
index e3919395ea..78cdc68088 100644
--- a/src/bin/pgbench/pgbench.c
+++ b/src/bin/pgbench/pgbench.c
@@ -822,6 +822,7 @@ static void setDoubleValue(PgBenchValue *pv, double dval);
 static bool evaluateExpr(CState *st, PgBenchExpr *expr,
 						 PgBenchValue *retval);
 static ConnectionStateEnum executeMetaCommand(CState *st, pg_time_usec_t *now);
+static void doLogHeader(FILE *logfile, double throttle_delay, uint32 retries);
 static void doLog(TState *thread, CState *st,
 				  StatsData *agg, bool skipped, double latency, double lag);
 static void processXactStats(TState *thread, CState *st, pg_time_usec_t *now,
@@ -4500,6 +4501,34 @@ getResultString(bool skipped, EStatus estatus)
 		return "failed";
 }
 
+/*
+ * Generates column headers for the log file
+ *
+ */
+void doLogHeader(FILE *logfile, double throttle_delay, uint32 retries)
+{
+    // header fields present in all cases
+    fprintf(logfile, "client_id transaction_no time script_no time_epoch time_us");
+    
+    // Append "schedule_lag" if the schedule_lag is true
+    if (throttle_delay)
+    {
+        fprintf(logfile, " schedule_lag");
+    }
+
+    // Append "retries" when set
+    if (retries > 1)
+    {
+        fprintf(logfile, " retries");
+    }
+
+    fprintf(logfile, "\n");
+
+	// flush the buffer to ensure the header is written immediately
+	fflush(logfile);
+}
+
+
 /*
  * Print log entry after completing one transaction.
  *
@@ -4517,7 +4546,6 @@ doLog(TState *thread, CState *st,
 	pg_time_usec_t now = pg_time_now() + epoch_shift;
 
 	Assert(use_log);
-
 	/*
 	 * Skip the log entry if sampling is enabled and this row doesn't belong
 	 * to the random sample.
@@ -7380,6 +7408,11 @@ threadRun(void *arg)
 
 		if (thread->logfile == NULL)
 			pg_fatal("could not open logfile \"%s\": %m", logpath);
+		else
+			// only log header from the main thread
+			if (thread->tid == 0) {
+				doLogHeader(thread->logfile, throttle_delay, max_tries);
+			}
 	}
 
 	/* explicitly initialize the state machines */
-- 
2.39.3 (Apple Git-145)



^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: [PATCH] pgbench log file headers
@ 2024-01-06 15:20  vignesh C <[email protected]>
  parent: Adam Hendel <[email protected]>
  0 siblings, 1 reply; 9+ messages in thread

From: vignesh C @ 2024-01-06 15:20 UTC (permalink / raw)
  To: Adam Hendel <[email protected]>; +Cc: Andres Freund <[email protected]>; [email protected]

On Tue, 21 Nov 2023 at 09:52, Adam Hendel <[email protected]> wrote:
>
> Hello,
>
> On Mon, Nov 13, 2023 at 6:01 PM Andres Freund <[email protected]> wrote:
>>
>> Hi,
>>
>> On 2023-11-13 11:55:07 -0600, Adam Hendel wrote:
>> > Currently, pgbench will log individual transactions to a logfile when the
>> > `--log` parameter flag is provided. The logfile, however, does not include
>> > column header. It has become a fairly standard expectation of users to have
>> > column headers present in flat files. Without the header in the pgbench log
>> > files, new users must navigate to the docs and piece together the column
>> > headers themselves. Most industry leading frameworks have tooling built in
>> > to read column headers though, for example python/pandas read_csv().
>>
>> The disadvantage of doing that is that a single pgbench run with --log will
>> generate many files when using -j, to avoid contention. The easiest way to
>> deal with that after the run is to cat all the log files to a larger one. If
>> you do that with headers present, you obviously have a few bogus rows (the
>> heades from the various files).
>>
>> I guess you could avoid the "worst" of that by documenting that the combined
>> log file should be built by
>>   cat {$log_prefix}.${pid} {$log_prefix}.${pid}.*
>> and only outputting the header in the file generated by the main thread.
>>
>>
>> > We can improve the experience for users by adding column headers to pgbench
>> > logfiles with an optional command line flag, `--log-header`. This will keep
>> > the API backwards compatible by making users opt-in to the column headers.
>> > It follows the existing pattern of having conditional flags in pgbench’s
>> > API; the `--log` option would have both –log-prefix and –log-header if this
>> > work is accepted.
>>
>> > The implementation considers the column headers only when the
>> > `--log-header` flag is present. The values for the columns are taken
>> > directly from the “Per-Transaction Logging” section in
>> > https://www.postgresql.org/docs/current/pgbench.html and takes into account
>> > the conditional columns `schedule_lag` and `retries`.
>> >
>> >
>> > Below is an example of what that logfile will look like:
>> >
>> >
>> > pgbench  postgres://postgres:postgres@localhost:5432/postgres --log
>> > --log-header
>> >
>> > client_id transaction_no time script_no time_epoch time_us
>>
>> Independent of your patch, but we imo ought to combine time_epoch time_us in
>> the log output. There's no point in forcing consumers to combine those fields,
>> and it makes logging more expensive...  And if we touch this, we should just
>> switch to outputting nanoseconds instead of microseconds.
>>
>> It also is quite odd that we have "time" and "time_epoch", "time_us", where
>> time is the elapsed time of an individual "transaction" and time_epoch +
>> time_us together are a wall-clock timestamp.  Without differentiating between
>> those, the column headers seem not very useful, because one needs to look in
>> the documentation to understand the fields.
>>
>>
>> I don't think there's all that strong a need for backward compatibility in
>> pgbench. We could just change the columns as I suggest above and then always
>> emit the header in the "main" log file.
>
>
> I updated the patch to always log the header and only off the main thread. As for the time headers, I will work on renaming/combining those in a separate commit as:

One of the test has failed in CFBOT at[1] with:
[09:15:00.526](0.000s) not ok 422 - transaction count for
/tmp/cirrus-ci-build/build/testrun/pgbench/001_pgbench_with_server/data/t_001_pgbench_with_server_main_data/001_pgbench_log_3.25193
(11)
[09:15:00.526](0.000s) #   Failed test 'transaction count for
/tmp/cirrus-ci-build/build/testrun/pgbench/001_pgbench_with_server/data/t_001_pgbench_with_server_main_data/001_pgbench_log_3.25193
(11)'
#   at /tmp/cirrus-ci-build/src/bin/pgbench/t/001_pgbench_with_server.pl
line 1257.
[09:15:00.526](0.000s) not ok 423 - transaction format for 001_pgbench_log_3
[09:15:00.526](0.000s) #   Failed test 'transaction format for
001_pgbench_log_3'
#   at /tmp/cirrus-ci-build/src/bin/pgbench/t/001_pgbench_with_server.pl
line 1257.
# Log entry not matching: client_id transaction_no time script_no
time_epoch time_us
# Running: pgbench --no-vacuum -f
/tmp/cirrus-ci-build/build/testrun/pgbench/001_pgbench_with_server/data/t_001_pgbench_with_server_main_data/001_pgbench_incomplete_transaction_block

More details for the same is available at [2]

[1] - https://cirrus-ci.com/task/5139049757802496
[2] - https://api.cirrus-ci.com/v1/artifact/task/5139049757802496/testrun/build/testrun/pgbench/001_pgbenc...

Regards,
Vignesh






^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: [PATCH] pgbench log file headers
@ 2024-03-31 05:10  Andrey M. Borodin <[email protected]>
  parent: vignesh C <[email protected]>
  0 siblings, 0 replies; 9+ messages in thread

From: Andrey M. Borodin @ 2024-03-31 05:10 UTC (permalink / raw)
  To: vignesh C <[email protected]>; +Cc: Adam Hendel <[email protected]>; Andres Freund <[email protected]>; [email protected]



> On 6 Jan 2024, at 20:20, vignesh C <[email protected]> wrote:
> 
> One of the test has failed in CFBOT at[1] with:

Hi Adam,

This is a kind reminder that CF entry [0] is waiting for an update. Thanks!


Best regards, Andrey Borodin.

[0] https://commitfest.postgresql.org/47/4660/






^ permalink  raw  reply  [nested|flat] 9+ messages in thread


end of thread, other threads:[~2024-03-31 05:10 UTC | newest]

Thread overview: 9+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2021-04-04 04:30 [PATCH v60 08/17] pgstat: Introduce pgstat_relation_should_count(). Andres Freund <[email protected]>
2022-03-03 02:02 [PATCH v65 02/11] pgstat: Introduce pgstat_relation_should_count(). Andres Freund <[email protected]>
2023-11-13 17:55 [PATCH] pgbench log file headers Adam Hendel <[email protected]>
2023-11-13 19:12 ` Re: [PATCH] pgbench log file headers Andrew Atkinson <[email protected]>
2023-11-14 00:01 ` Re: [PATCH] pgbench log file headers Andres Freund <[email protected]>
2023-11-15 14:16   ` Re: [PATCH] pgbench log file headers Adam Hendel <[email protected]>
2023-11-21 04:22   ` Re: [PATCH] pgbench log file headers Adam Hendel <[email protected]>
2024-01-06 15:20     ` Re: [PATCH] pgbench log file headers vignesh C <[email protected]>
2024-03-31 05:10       ` Re: [PATCH] pgbench log file headers Andrey M. Borodin <[email protected]>

This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox