Front ported improvements

CORE-3656 : Support for sweep information in Trace API, and
CORE-2668 : Write note into log when automatic sweep is started
Also per-table stats is enabled at transaction level (see thread_db::bumpRelStats)

src/jrd/jrd.h

@@ -507,7 +507,7 @@ public:
 	void bumpRelStats(const RelStatType index, SLONG relation_id)
 	{
 		reqStat->bumpRelValue(index, relation_id);
-		//traStat->bumpRelValue(index, relation_id);
+		traStat->bumpRelValue(index, relation_id);
 		//attStat->bumpRelValue(index, relation_id);
 		//dbbStat->bumpRelValue(index, relation_id);
 	}

src/jrd/ntrace.h

@@ -42,6 +42,14 @@ enum ntrace_connection_kind_t
 	connection_service
 };
 
+enum ntrace_process_state_t
+{
+	process_state_started	= 1,
+	process_state_finished,
+	process_state_failed,
+	process_state_progress
+};
+
 class TraceBaseConnection : public Firebird::IVersioned
 {
 public:
@@ -184,6 +192,18 @@ public:
 #define FB_TRACE_STATUS_VERSION (FB_VERSIONED_VERSION + 4)
 
 
+class TraceSweepInfo : public Firebird::IVersioned
+{
+public:
+	virtual TraNumber FB_CARG getOIT() = 0;
+	virtual TraNumber FB_CARG getOST() = 0;
+	virtual TraNumber FB_CARG getOAT() = 0;
+	virtual TraNumber FB_CARG getNext() = 0;
+	virtual PerformanceInfo* FB_CARG getPerf() = 0;
+};
+#define FB_TRACE_SWEEP_INFO_VERSION (FB_VERSIONED_VERSION + 5)
+
+
 // Plugin-specific argument. Passed by the engine to each hook
 typedef void* ntrace_object_t;
 
@@ -325,8 +345,12 @@ public:
 
 	// Errors happened
 	virtual ntrace_boolean_t FB_CARG trace_event_error(TraceBaseConnection* connection, TraceStatusVector* status, const char* function) = 0;
+
+	// Sweep activity
+	virtual ntrace_boolean_t FB_CARG trace_event_sweep(TraceDatabaseConnection* connection, TraceSweepInfo* sweep, 
+			ntrace_process_state_t sweep_state) = 0;
 };
-#define FB_TRACE_PLUGIN_VERSION (FB_REFCOUNTED_VERSION + 19)
+#define FB_TRACE_PLUGIN_VERSION (FB_REFCOUNTED_VERSION + 20)
 
 // Trace plugin second level factory (this is what is known to PluginManager as "trace plugin")
 class TraceFactory : public Firebird::IPluginBase
@@ -361,6 +385,7 @@ enum TraceEvent
 	TRACE_EVENT_SERVICE_QUERY,
 	TRACE_EVENT_SERVICE_DETACH,
 	TRACE_EVENT_ERROR,
+	TRACE_EVENT_SWEEP,
 	TRACE_EVENT_MAX					// keep it last
 };
 

src/jrd/tra.cpp

@@ -1619,6 +1619,10 @@ bool TRA_sweep(thread_db* tdbb, jrd_tra* trans)
 	if (dbb->dbb_flags & DBB_sweep_in_progress)
 		return true;
 
+	if (tdbb->getAttachment()->att_flags & ATT_no_cleanup) {
+		return true;
+	}
+
 	// fill out a lock block, zeroing it out first
 
 	Lock temp_lock(tdbb, 0, LCK_sweep, trans);
@@ -1660,6 +1664,7 @@ bool TRA_sweep(thread_db* tdbb, jrd_tra* trans)
 	TraNumber transaction_oldest_active = transaction->tra_oldest_active;
 	tdbb->setTransaction(transaction);
 
+	TraceSweepEvent traceSweep(tdbb);
 
 	// The garbage collector runs asynchronously with respect to
 	// our database sweep. This isn't good enough since we must
@@ -1670,7 +1675,7 @@ bool TRA_sweep(thread_db* tdbb, jrd_tra* trans)
 
 	transaction->tra_attachment->att_flags &= ~ATT_notify_gc;
 
-	if (VIO_sweep(tdbb, transaction))
+	if (VIO_sweep(tdbb, transaction, &traceSweep))
 	{
 		const ULONG base = transaction->tra_oldest & ~TRA_MASK;
 		TraNumber active = transaction->tra_oldest;
@@ -1711,7 +1716,11 @@ bool TRA_sweep(thread_db* tdbb, jrd_tra* trans)
 			header->hdr_oldest_transaction = MIN(active, (ULONG) transaction_oldest_active);
 		}
 
+		traceSweep.update(header);
+
 		CCH_RELEASE(tdbb, &window);
+
+		traceSweep.report(process_state_finished);
 	}
 
 	if (!trans)
@@ -1725,6 +1734,8 @@ bool TRA_sweep(thread_db* tdbb, jrd_tra* trans)
 	}	// try
 	catch (const Firebird::Exception& ex)
 	{
+		iscLogException("Error during sweep:", ex);
+
 		Firebird::stuff_exception(tdbb->tdbb_status_vector, ex);
 		try {
 			if (!trans && transaction)
@@ -3359,3 +3370,103 @@ UserManagement* jrd_tra::getUserManagement()
 	return tra_user_management;
 }
 
+
+/// class TraceSweepEvent
+
+TraceSweepEvent::TraceSweepEvent(thread_db* tdbb)
+{
+	m_tdbb = tdbb;
+
+	WIN window(HEADER_PAGE_NUMBER);
+	Ods::header_page *header = (Ods::header_page*) CCH_FETCH(m_tdbb, &window, LCK_read, pag_header);
+
+	m_sweep_info.update(header);
+	CCH_RELEASE(m_tdbb, &window);
+
+	Attachment* att = m_tdbb->getAttachment();
+
+	gds__log("Sweep is started by %s\n"
+		"\tDatabase \"%s\" \n"
+		"\tOIT %lu, OAT %lu, OST %lu, Next %lu",
+		att->att_user->usr_user_name.c_str(),
+		att->att_filename.c_str(),
+		m_sweep_info.getOIT(),
+		m_sweep_info.getOAT(),
+		m_sweep_info.getOST(),
+		m_sweep_info.getNext());
+
+	TraceManager* trace_mgr = att->att_trace_manager;
+
+	m_need_trace = trace_mgr->needs(TRACE_EVENT_SWEEP);
+
+	if (!m_need_trace)
+		return;
+
+	m_start_clock = fb_utils::query_performance_counter();
+
+	TraceConnectionImpl conn(att);
+	trace_mgr->event_sweep(&conn, &m_sweep_info, process_state_started);
+
+	m_relation_clock = fb_utils::query_performance_counter();
+	m_relation_stats.assign(m_tdbb->getTransaction()->tra_stats);
+}
+
+
+TraceSweepEvent::~TraceSweepEvent()
+{
+	m_tdbb->setRequest(NULL);
+	report(process_state_failed);
+}
+
+
+void TraceSweepEvent::report(ntrace_process_state_t state, jrd_rel* relation)
+{
+	Attachment* att = m_tdbb->getAttachment();
+
+	if (state == process_state_finished) 
+	{
+		gds__log("Sweep is finished\n"
+			"\tDatabase \"%s\" \n"
+			"\tOIT %lu, OAT %lu, OST %lu, Next %lu",
+			att->att_filename.c_str(),
+			m_sweep_info.getOIT(),
+			m_sweep_info.getOAT(),
+			m_sweep_info.getOST(),
+			m_sweep_info.getNext());
+	}
+
+	if (!m_need_trace)
+		return;
+
+	Database* dbb = m_tdbb->getDatabase();
+	TraceManager* trace_mgr = att->att_trace_manager;
+
+	TraceConnectionImpl conn(att);
+
+	if (relation && relation->rel_name.isEmpty())
+	{
+		// don't accumulate per-relation stats for metadata query below
+		MET_lookup_relation_id(m_tdbb, relation->rel_id, false);
+	}
+
+	// we need to compare stats against zero base 
+	if (state != process_state_progress)
+		m_relation_stats.reset(); 
+
+	jrd_tra* tran = m_tdbb->getTransaction();
+
+	TraceRuntimeStats stats(att, &m_relation_stats, 
+		state == process_state_progress ? &tran->tra_stats : &att->att_stats,
+		fb_utils::query_performance_counter() - (state == process_state_progress ? 
+			m_relation_clock : m_start_clock), 
+		0);
+
+	m_relation_clock = fb_utils::query_performance_counter();
+	m_relation_stats.assign(m_tdbb->getTransaction()->tra_stats);
+
+	m_sweep_info.setPerf(stats.getPerf());
+	trace_mgr->event_sweep(&conn, &m_sweep_info, state);
+
+	if (state == process_state_failed || state == process_state_finished)
+		m_need_trace = false;
+}

src/jrd/trace/TraceJrdHelpers.h

@@ -412,6 +412,31 @@ private:
 };
 
 
+class TraceSweepEvent
+{
+	// implementation is at tra.cpp
+public:
+	TraceSweepEvent(thread_db* tdbb);
+
+	~TraceSweepEvent();
+
+	void update(const Ods::header_page* header)
+	{
+		m_sweep_info.update(header);
+	}
+
+	void report(ntrace_process_state_t state, jrd_rel* relation = 0);
+
+private:
+	bool				m_need_trace;
+	thread_db*			m_tdbb;
+	TraceSweepImpl		m_sweep_info;
+	SINT64				m_start_clock;
+	SINT64				m_relation_clock;
+	RuntimeStatistics	m_relation_stats;
+};
+
+
 } // namespace Jrd
 
 #endif // JRD_TRACE_JRD_HELPERS_H

src/jrd/trace/TraceManager.cpp

@@ -485,4 +485,12 @@ void TraceManager::event_error(TraceBaseConnection* connection, TraceStatusVecto
 		(connection, status, function));
 }
 
+
+void TraceManager::event_sweep(TraceDatabaseConnection* connection, TraceSweepInfo* sweep, 
+		ntrace_process_state_t sweep_state)
+{
+	EXECUTE_HOOKS(trace_event_sweep,
+		(connection, sweep, sweep_state));
+}
+
 }

src/jrd/trace/TraceManager.h

@@ -111,6 +111,9 @@ public:
 
 	void event_error(TraceBaseConnection* connection, TraceStatusVector* status, const char* function);
 
+	void event_sweep(TraceDatabaseConnection* connection, TraceSweepInfo* sweep, 
+			ntrace_process_state_t sweep_state);
+
 	typedef ntrace_mask_t NotificationNeeds;
 
 	inline bool needs(TraceEvent e)

src/jrd/trace/TraceObjects.h

@@ -422,6 +422,45 @@ private:
 	Firebird::string m_error;
 };
 
+class TraceSweepImpl : public Firebird::AutoIface<TraceSweepInfo, FB_TRACE_SWEEP_INFO_VERSION>
+{
+public:
+	TraceSweepImpl()
+	{
+		m_oit = 0;
+		m_ost = 0;
+		m_oat = 0;
+		m_next = 0;
+		m_perf = 0;
+	}
+
+	void update(const Ods::header_page* header)
+	{
+		m_oit = header->hdr_oldest_transaction;
+		m_ost = header->hdr_oldest_snapshot;
+		m_oat = header->hdr_oldest_active;
+		m_next = header->hdr_next_transaction;
+	}
+
+	void setPerf(PerformanceInfo* perf)
+	{
+		m_perf = perf;
+	}
+
+	virtual TraNumber FB_CARG getOIT()	{ return m_oit; };
+	virtual TraNumber FB_CARG getOST()	{ return m_ost; };
+	virtual TraNumber FB_CARG getOAT()	{ return m_oat; };
+	virtual TraNumber FB_CARG getNext()	{ return m_next; };
+	virtual PerformanceInfo* FB_CARG getPerf()	{ return m_perf; };
+
+private:
+	TraNumber m_oit;
+	TraNumber m_ost;
+	TraNumber m_oat;
+	TraNumber m_next;
+	PerformanceInfo* m_perf;
+};
+
 } // namespace Jrd
 
 #endif // JRD_TRACE_OBJECTS_H

src/jrd/vio.cpp

@@ -91,6 +91,8 @@
 #include "../jrd/Function.h"
 #include "../common/StatusArg.h"
 #include "../jrd/GarbageCollector.h"
+#include "../jrd/trace/TraceManager.h"
+#include "../jrd/trace/TraceJrdHelpers.h"
 
 using namespace Jrd;
 using namespace Firebird;
@@ -3210,7 +3212,7 @@ void VIO_store(thread_db* tdbb, record_param* rpb, jrd_tra* transaction)
 }
 
 
-bool VIO_sweep(thread_db* tdbb, jrd_tra* transaction)
+bool VIO_sweep(thread_db* tdbb, jrd_tra* transaction, TraceSweepEvent* traceSweep)
 {
 /**************************************
  *
@@ -3253,6 +3255,7 @@ bool VIO_sweep(thread_db* tdbb, jrd_tra* transaction)
 
 		for (size_t i = 1; (vector = attachment->att_relations) && i < vector->count(); i++)
 		{
+			bool haveRecs = false;
 			if ((relation = (*vector)[i]) && !(relation->rel_flags & (REL_deleted | REL_deleting)) &&
 				 relation->getPages(tdbb)->rel_pages)
 			{
@@ -3275,7 +3278,13 @@ bool VIO_sweep(thread_db* tdbb, jrd_tra* transaction)
 						JRD_reschedule(tdbb, SWEEP_QUANTUM, true);
 					}
 					transaction->tra_oldest_active = dbb->dbb_oldest_snapshot;
+					haveRecs = true;
 				}
+
+				if (haveRecs) {
+					traceSweep->report(process_state_progress, relation);
+				}
+
 				--relation->rel_sweep_count;
 				--relation->rel_scan_count;
 			}

src/jrd/vio_proto.h

@@ -34,6 +34,7 @@ namespace Jrd {
 	struct record_param;
 	class Savepoint;
 	class Format;
+	class TraceSweepEvent;
 }
 
 void	VIO_backout(Jrd::thread_db*, Jrd::record_param*, const Jrd::jrd_tra*);
@@ -58,7 +59,7 @@ Jrd::Record*	VIO_record(Jrd::thread_db*, Jrd::record_param*, const Jrd::Format*,
 void	VIO_refetch_record(Jrd::thread_db*, Jrd::record_param*, Jrd::jrd_tra*);
 void	VIO_start_save_point(Jrd::thread_db*, Jrd::jrd_tra*);
 void	VIO_store(Jrd::thread_db*, Jrd::record_param*, Jrd::jrd_tra*);
-bool	VIO_sweep(Jrd::thread_db*, Jrd::jrd_tra*);
+bool	VIO_sweep(Jrd::thread_db*, Jrd::jrd_tra*, Jrd::TraceSweepEvent*);
 void	VIO_verb_cleanup(Jrd::thread_db*, Jrd::jrd_tra*);
 IPTR	VIO_savepoint_large(const Jrd::Savepoint*, IPTR);
 void	VIO_temp_cleanup(Jrd::jrd_tra*);

src/utilities/ntrace/TracePluginImpl.cpp

@@ -1971,6 +1971,59 @@ void TracePluginImpl::log_event_error(TraceBaseConnection* connection, TraceStat
 	logRecordError(event_type.c_str(), connection, status);
 }
 
+void TracePluginImpl::log_event_sweep(TraceDatabaseConnection* connection, TraceSweepInfo* sweep, 
+	ntrace_process_state_t sweep_state)
+{
+	if (sweep_state == process_state_started ||
+		sweep_state == process_state_finished) 
+	{
+		record.printf("\nTransaction counters:\n"
+			"\tOldest interesting %10ld\n"
+			"\tOldest active      %10ld\n"
+			"\tOldest snapshot    %10ld\n"
+			"\tNext transaction   %10ld\n",
+			sweep->getOIT(),
+			sweep->getOAT(),
+			sweep->getOST(),
+			sweep->getNext()
+			);
+	}
+
+	PerformanceInfo* info = sweep->getPerf();
+	if (info)
+	{
+		appendGlobalCounts(info);
+		appendTableCounts(info);
+	}
+
+	const char* event_type = NULL;
+	switch (sweep_state)
+	{
+	case process_state_started:
+		event_type = "SWEEP_START";
+		break;
+
+	case process_state_finished:
+		event_type = "SWEEP_FINISH";
+		break;
+
+	case process_state_failed:
+		event_type = "SWEEP_FAILED";
+		break;
+
+	case process_state_progress:
+		event_type = "SWEEP_PROGRESS";
+		break;
+
+	default:
+		fb_assert(false);
+		event_type = "Unknown SWEEP process state";
+		break;
+	}
+
+	logRecordConn(event_type, connection);
+}
+
 //***************************** PLUGIN INTERFACE ********************************
 
 int TracePluginImpl::release()
@@ -2339,3 +2392,20 @@ ntrace_boolean_t TracePluginImpl::trace_event_error(TraceBaseConnection* connect
 		return false;
 	}
 }
+
+ntrace_boolean_t TracePluginImpl::trace_event_sweep(TraceDatabaseConnection* connection, TraceSweepInfo* sweep, 
+		ntrace_process_state_t sweep_state)
+{
+	try
+	{
+		MasterInterfacePtr()->upgradeInterface(connection, FB_TRACE_CONNECTION_VERSION, upInfo);
+		MasterInterfacePtr()->upgradeInterface(sweep, FB_TRACE_SWEEP_INFO_VERSION, upInfo);
+		log_event_sweep(connection, sweep, sweep_state);
+		return true;
+	}
+	catch(const Firebird::Exception& ex)
+	{
+		marshal_exception(ex);
+		return false;
+	}
+}

src/utilities/ntrace/TracePluginImpl.h

@@ -255,6 +255,8 @@ private:
 
 	void log_event_error(TraceBaseConnection* connection, TraceStatusVector* status, const char* function);
 
+	void log_event_sweep(TraceDatabaseConnection* connection, TraceSweepInfo* sweep, ntrace_process_state_t sweep_state);
+
 	// TracePlugin implementation
 	int FB_CARG release();
 	const char* FB_CARG trace_get_error();
@@ -306,6 +308,10 @@ private:
 
 	// Errors happened
 	virtual ntrace_boolean_t FB_CARG trace_event_error(TraceBaseConnection* connection, TraceStatusVector* status, const char* function);
+
+	// Sweep activity
+	virtual ntrace_boolean_t FB_CARG trace_event_sweep(TraceDatabaseConnection* connection, TraceSweepInfo* sweep, 
+			ntrace_process_state_t sweep_state);
 };
 
 

src/utilities/ntrace/fbtrace.conf

@@ -87,6 +87,9 @@ database
 	# Put errors happened
 	#log_errors false
 
+	# Sweep activity
+	#log_sweep false
+
 
 	# Print access path (plan) with sql statement
 	#print_plan = false

src/utilities/ntrace/paramtable.h

@@ -58,6 +58,7 @@ BOOL_PARAMETER(log_blr_requests, false)
 BOOL_PARAMETER(print_blr, false)
 BOOL_PARAMETER(log_dyn_requests, false)
 BOOL_PARAMETER(print_dyn, false)
+BOOL_PARAMETER(log_sweep, false)
 UINT_PARAMETER(max_sql_length, 300)
 UINT_PARAMETER(max_blr_length, 500)
 UINT_PARAMETER(max_dyn_length, 500)